From 2ab029c7428eb3e4894e7d165815c90fbc39a8b2 Mon Sep 17 00:00:00 2001 From: Philip Chimento Date: Sun, 12 Feb 2012 00:33:39 +0100 Subject: [PATCH] Update Glulxe to 0.4.7 --- interpreters/glulxe/README | 7 +- interpreters/glulxe/exec.c | 20 +-- interpreters/glulxe/funcs.c | 8 +- interpreters/glulxe/gestalt.c | 2 +- interpreters/glulxe/glkop.c | 49 +++++++- interpreters/glulxe/glulxe.h | 15 +-- interpreters/glulxe/heap.c | 2 +- interpreters/glulxe/profile-analyze.py | 163 +++++++++++++++++++------ interpreters/glulxe/profile.c | 147 ++++++++++++++++++---- interpreters/glulxe/search.c | 1 - interpreters/glulxe/serial.c | 11 +- interpreters/glulxe/string.c | 4 +- interpreters/glulxe/unixstrt.c | 61 +++++++-- 13 files changed, 375 insertions(+), 115 deletions(-) diff --git a/interpreters/glulxe/README b/interpreters/glulxe/README index e903d1e..952e8dd 100644 --- a/interpreters/glulxe/README +++ b/interpreters/glulxe/README @@ -1,5 +1,5 @@ Glulxe: the Glulx VM interpreter -Version 0.4.### +Version 0.4.7 Designed by Andrew Plotkin http://eblong.com/zarf/glulx/index.html @@ -34,9 +34,12 @@ comment out the "#define FLOAT_SUPPORT" line in glulxe.h. * Version -###: +0.4.7: Abstracted powf() to an osdepend wrapper. (Needed for Windows.) Fixed a @ceil bug, for some C math libraries. + Improved the profiling system in several ways. + Fixed a bug in glkop.c dispatching, to do with optional array + arguments. 0.4.6: Added floating-point math feature. diff --git a/interpreters/glulxe/exec.c b/interpreters/glulxe/exec.c index 4dd3fcd..af69189 100644 --- a/interpreters/glulxe/exec.c +++ b/interpreters/glulxe/exec.c @@ -523,27 +523,27 @@ void execute_loop() break; case op_streamchar: - profile_in(2, FALSE); + profile_in(0xE0000001, stackptr, FALSE); value = inst[0].value & 0xFF; (*stream_char_handler)(value); - profile_out(); + profile_out(stackptr); break; case op_streamunichar: - profile_in(2, FALSE); + profile_in(0xE0000002, stackptr, FALSE); value = inst[0].value; (*stream_unichar_handler)(value); - profile_out(); + profile_out(stackptr); break; case op_streamnum: - profile_in(2, FALSE); + profile_in(0xE0000003, stackptr, FALSE); vals0 = inst[0].value; stream_num(vals0, FALSE, 0); - profile_out(); + profile_out(stackptr); break; case op_streamstr: - profile_in(2, FALSE); + profile_in(0xE0000004, stackptr, FALSE); stream_string(inst[0].value, 0, 0); - profile_out(); + profile_out(stackptr); break; default: @@ -615,12 +615,12 @@ void execute_loop() break; case op_glk: - profile_in(1, FALSE); + profile_in(0xF0000000+inst[0].value, stackptr, FALSE); value = inst[1].value; arglist = pop_arguments(value, 0); val0 = perform_glk(inst[0].value, value, arglist); store_operand(inst[2].desttype, inst[2].value, val0); - profile_out(); + profile_out(stackptr); break; case op_random: diff --git a/interpreters/glulxe/funcs.c b/interpreters/glulxe/funcs.c index c0aac4d..2e03ccd 100644 --- a/interpreters/glulxe/funcs.c +++ b/interpreters/glulxe/funcs.c @@ -23,14 +23,14 @@ void enter_function(glui32 addr, glui32 argc, glui32 *argv) accelfunc = accel_get_func(addr); if (accelfunc) { - profile_in(addr, TRUE); + profile_in(addr, stackptr, TRUE); val = accelfunc(argc, argv); - profile_out(); + profile_out(stackptr); pop_callstub(val); return; } - profile_in(addr, FALSE); + profile_in(addr, stackptr, FALSE); /* Check the Glulx type identifier byte. */ functype = Mem1(addr); @@ -190,8 +190,8 @@ void enter_function(glui32 addr, glui32 argc, glui32 *argv) */ void leave_function() { + profile_out(stackptr); stackptr = frameptr; - profile_out(); } /* push_callstub(): diff --git a/interpreters/glulxe/gestalt.c b/interpreters/glulxe/gestalt.c index 87a8182..7f6418d 100644 --- a/interpreters/glulxe/gestalt.c +++ b/interpreters/glulxe/gestalt.c @@ -15,7 +15,7 @@ glui32 do_gestalt(glui32 val, glui32 val2) return 0x00030102; /* Glulx spec version 3.1.2 */ case gestulx_TerpVersion: - return 0x00000406; /* Glulxe version 0.4.6 */ + return 0x00000407; /* Glulxe version 0.4.7 */ case gestulx_ResizeMem: #ifdef FIXED_MEMSIZE diff --git a/interpreters/glulxe/glkop.c b/interpreters/glulxe/glkop.c index e761cd7..090632a 100644 --- a/interpreters/glulxe/glkop.c +++ b/interpreters/glulxe/glkop.c @@ -120,6 +120,8 @@ typedef struct classtable_struct { static int num_classes = 0; classtable_t **classes = NULL; +static glui32 find_id_for_stream(strid_t str); + static classtable_t *new_classtable(glui32 firstid); static void *classes_get(int classid, glui32 objid); static classref_t *classes_put(int classid, void *obj); @@ -185,6 +187,16 @@ glui32 perform_glk(glui32 funcnum, glui32 numargs, glui32 *arglist) directly -- instead of bothering with the whole prototype mess. */ + case 0x0047: /* stream_set_current */ + if (numargs != 1) + goto WrongArgNum; + glk_stream_set_current(find_stream_by_id(arglist[0])); + break; + case 0x0048: /* stream_get_current */ + if (numargs != 0) + goto WrongArgNum; + retval = find_id_for_stream(glk_stream_get_current()); + break; case 0x0080: /* put_char */ if (numargs != 1) goto WrongArgNum; @@ -205,6 +217,16 @@ glui32 perform_glk(glui32 funcnum, glui32 numargs, glui32 *arglist) goto WrongArgNum; retval = glk_char_to_upper(arglist[0] & 0xFF); break; + case 0x0128: /* put_char_uni */ + if (numargs != 1) + goto WrongArgNum; + glk_put_char_uni(arglist[0]); + break; + case 0x012B: /* put_char_stream_uni */ + if (numargs != 2) + goto WrongArgNum; + glk_put_char_stream_uni(find_stream_by_id(arglist[0]), arglist[1]); + break; WrongArgNum: fatal_error("Wrong number of arguments to Glk function."); @@ -214,7 +236,7 @@ glui32 perform_glk(glui32 funcnum, glui32 numargs, glui32 *arglist) /* Go through the full dispatcher prototype foo. */ char *proto, *cx; dispatch_splot_t splot; - int argnum; + int argnum, argnum2; /* Grab the string. */ proto = gidispatch_prototype(funcnum); @@ -243,9 +265,11 @@ glui32 perform_glk(glui32 funcnum, glui32 numargs, glui32 *arglist) gidispatch_call(funcnum, argnum, splot.garglist); /* Phase 3. */ - argnum = 0; + argnum2 = 0; cx = proto; - unparse_glk_args(&splot, &cx, 0, &argnum, 0, 0); + unparse_glk_args(&splot, &cx, 0, &argnum2, 0, 0); + if (argnum != argnum2) + fatal_error("Argument counts did not match."); break; } @@ -605,6 +629,8 @@ static void parse_glk_args(dispatch_splot_t *splot, char **proto, int depth, } else { cx++; + if (isarray) + ix++; } } } @@ -807,6 +833,8 @@ static void unparse_glk_args(dispatch_splot_t *splot, char **proto, int depth, } else { cx++; + if (isarray) + ix++; } } } @@ -838,6 +866,21 @@ strid_t find_stream_by_id(glui32 objid) return classes_get(1, objid); } +/* find_id_for_stream(): + The converse of find_stream_by_id(). + This is only needed in this file, so it's static. +*/ +static glui32 find_id_for_stream(strid_t str) +{ + gidispatch_rock_t objrock; + + if (!str) + return 0; + + objrock = gidispatch_get_objrock(str, 1); + return ((classref_t *)objrock.ptr)->id; +} + /* Build a hash table to hold a set of Glk objects. */ static classtable_t *new_classtable(glui32 firstid) { diff --git a/interpreters/glulxe/glulxe.h b/interpreters/glulxe/glulxe.h index 72308a6..64a9f7f 100644 --- a/interpreters/glulxe/glulxe.h +++ b/interpreters/glulxe/glulxe.h @@ -254,20 +254,21 @@ extern glui32 perform_glk(glui32 funcnum, glui32 numargs, glui32 *arglist); extern strid_t find_stream_by_id(glui32 objid); /* profile.c */ +extern void setup_profile(strid_t stream, char *filename); extern int init_profile(void); #if VM_PROFILING extern glui32 profile_opcount; #define profile_tick() (profile_opcount++) -extern void profile_in(glui32 addr, int accel); -extern void profile_out(void); +extern void profile_in(glui32 addr, glui32 stackuse, int accel); +extern void profile_out(glui32 stackuse); extern void profile_fail(char *reason); extern void profile_quit(void); #else /* VM_PROFILING */ -#define profile_tick() (0) -#define profile_in(addr, accel) (0) -#define profile_out() (0) -#define profile_fail(reason) (0) -#define profile_quit() (0) +#define profile_tick() (0) +#define profile_in(addr, stackuse, accel) (0) +#define profile_out(stackuse) (0) +#define profile_fail(reason) (0) +#define profile_quit() (0) #endif /* VM_PROFILING */ /* accel.c */ diff --git a/interpreters/glulxe/heap.c b/interpreters/glulxe/heap.c index ea5bf24..d025fb5 100644 --- a/interpreters/glulxe/heap.c +++ b/interpreters/glulxe/heap.c @@ -266,7 +266,7 @@ void heap_free(glui32 addr) */ int heap_get_summary(glui32 *valcount, glui32 **summary) { - glui32 *arr, len, pos, lx; + glui32 *arr, len, pos; heapblock_t *blo; *valcount = 0; diff --git a/interpreters/glulxe/profile-analyze.py b/interpreters/glulxe/profile-analyze.py index c7f7345..ae2b2fb 100644 --- a/interpreters/glulxe/profile-analyze.py +++ b/interpreters/glulxe/profile-analyze.py @@ -11,29 +11,36 @@ Optionally, this script can also read the debug output of the Inform 6 compiler (or the assembly output), and use that to figure out the names of all the functions that were profiled. +You can also generate profiling output in the same form as dumbfrotz's +Z-machine profiling output. (If that happens to be what you want.) Use +the --dumbfrotz argument. + Using this script is currently a nuisance. The requirements: - You must compile Glulxe with profiling (the VM_PROFILING compile-time option). - (If you want function names) you should compile your Inform 6 source using the -k switch. This generates a "gameinfo.dbg" file. -- Run Glulxe, play some of the game, and quit. This generates a data - file called "profile-raw". +- Run Glulxe, using the "--profile profile-raw" option. Play some of + the game, and quit. This generates a data file called "profile-raw". - Run this script, giving gameinfo.dbg and profile-raw as arguments. + (You can provide dispatch_dump.xml as an optional third argument. + This file gives the names of Glk functions; it is available from + https://github.com/erkyrath/glk-dev/tree/master/dispatch_dump .) To sum up, in command-line form: % inform -G -k game.inf -% glulxe game.ulx -% python profile-analyze.py profile-raw gameinfo.dbg +% glulxe --profile profile-raw game.ulx +% python profile-analyze.py profile-raw gameinfo.dbg dispatch_dump.xml You can also use the assembly output of the Inform compiler, which you get with the -a switch. Save the output and use it instead of the debug file: % inform -G -a game.inf > game.asm -% glulxe game.ulx -% python profile-analyze.py profile-raw game.asm +% glulxe --profile profile-raw game.ulx +% python profile-analyze.py profile-raw game.asm dispatch_dump.xml The limitations: @@ -50,10 +57,14 @@ you use that data, these will not be named; they will be listed as often the most costly ones. (Therefore, you'll almost certainly want to use -k.) +If you leave off the "dispatch_dump.xml" argument, everything will +still work, but @glk function entries will be listed by number rather +than by name. + You can explore the profiling data in more detail by running the script interactively: -% python -i profile-analyze.py profile-raw game.asm +% python -i profile-analyze.py profile-raw game.asm dispatch_dump.xml After it runs, you'll be left at a Python prompt. The environment will contain mappings called "functions" (mapping addresses to @@ -89,27 +100,35 @@ A Function object has lots of attributes: function). self_ops=INT: The number of opcodes executed during all calls to the function, excluding time spent in subcalls. + max_depth=INT: The deepest this function has been nested on the + stack, during any call. + max_stack_use=INT: The greatest number of words on the stack, during + any call. (This is measured when the function returns, so it may + not capture the peak stack usage. If a function never returns, e.g. + Main__(), then this value is approximate.) (The self_time is the "cost" used for the original listing.) Note that if a function does not make any function calls, total_time will be the same as self_time (and total_ops the same as self_ops). -Two special function entries may be included. The function with address -"1" (which is not a legal Glulx function address) represents time spent -in @glk opcode calls. This will typically have a large self_time, -because it includes all the time spent waiting for input. +Some of the function entries refer to special interpreter operations. +(These have high addresses, outside the range of normal game files.) +Functions with addresses in the 0xE0000000 range are the interpreter's +output opcodes: @streamchar, @streamunichar, @streamnum, @streamstr. -The function with address "2" represents the time spent printing string -data (the @streamchar, @streamunichar, @streamnum, and @streamstr -opcodes). +Functions with addresses in the 0xF0000000 range are @glk opcode calls. +The number in the lower bits specifies which Glk function was called. +You will always see a large self_time for function 0xF00000C0; this +represents all the time spent waiting for input in glk_select(). -(Both "1" and "2" represent time spent in the Glk library, but they -get there by different code paths.) +(Both the 0xE0000000 and 0xF0000000 entries represent time spent in the +Glk library, but they get there by different code paths.) -The function with the lowest address (ignoring "1" and "2") is the -top-level Main__() function generated by the compiler. Its total_time -is the running time of the entire program. +The function with the lowest address is the top-level Main__() +function generated by the compiler. Its total_time is the running time +of the entire program; its total_ops is the number of opcodes executed +by the entire program; its max_depth is zero. """ @@ -117,8 +136,14 @@ import sys, os.path import xml.sax from struct import unpack +dumb_frotz_mode = False + +if ('--dumbfrotz' in sys.argv): + sys.argv.remove('--dumbfrotz') + dumb_frotz_mode = True + if (len(sys.argv) < 2): - print "Usage: profile-analyze.py profile-raw [ gameinfo.dbg | game.asm ]" + print "Usage: profile-analyze.py [--dumbfrotz] profile-raw [ gameinfo.dbg | game.asm ] [ dispatch_dump.xml ]" sys.exit(1) profile_raw = sys.argv[1] @@ -133,10 +158,21 @@ if (len(sys.argv) >= 3): print 'File not readable:', game_asm sys.exit(1) +dispatch_dump = None +if (len(sys.argv) >= 4): + dispatch_dump = sys.argv[3] + if (not os.path.exists(dispatch_dump)): + print 'File not readable:', dispatch_dump + sys.exit(1) + special_functions = { - 1: 'glk', 2: 'streamout' + 0xE0000001: 'streamchar', + 0xE0000002: 'streamunichar', + 0xE0000003: 'streamnum', + 0xE0000004: 'streamstr', } -max_special_functions = max(special_functions.keys()) + +glk_functions = {} functions = None sourcemap = None @@ -146,7 +182,14 @@ class Function: self.addr = addr self.hexaddr = hexaddr val = special_functions.get(addr) - if (val is None): + if (addr >= 0xF0000000): + name = glk_functions.get(addr-0xF0000000) + if (not name): + name = hex(addr-0xF0000000)[2:] + name = '$' + name.replace('L', '') + self.name = '<@glk_' + name + '>' + self.special = True + elif (val is None): self.name = '' self.special = False else: @@ -161,6 +204,10 @@ class Function: self.total_time = float(attrs['total_time']) self.self_ops = int(attrs['self_ops']) self.self_time = float(attrs['self_time']) + if (attrs.has_key('max_depth')): + self.max_depth = int(attrs['max_depth']) + if (attrs.has_key('max_stack_use')): + self.max_stack_use = int(attrs['max_stack_use']) def __repr__(self): return '' @@ -174,6 +221,23 @@ class Function: print ' %.6f sec (%d ops) spent executing' % (self.self_time, self.self_ops) print ' %.6f sec (%d ops) including child calls' % (self.total_time, self.total_ops) + def dump_dumbfrotz_style(self): + percent1 = ' ' + percent2 = ' ' + pc1 = int(100*(float(self.self_ops)/float(ops_executed))) + pc2 = int(100*(float(self.total_ops)/float(ops_executed))) + if (pc1 > 0): + percent1 = "%3d%%" % pc1 + if (pc2 > 0): + percent2 = "%3d%%" % pc2 + print '%-36s %s %-10lu %s %-10lu %-10lu %-4d' % (self.name, percent1, self.self_ops, percent2, self.total_ops, self.call_count, self.max_depth) + +class DispatchDumpHandler(xml.sax.handler.ContentHandler): + def startElement(self, name, attrs): + if (name == 'function'): + addr = int(attrs['id']) + glk_functions[addr] = str(attrs['name']) + class ProfileRawHandler(xml.sax.handler.ContentHandler): def startElement(self, name, attrs): global functions @@ -304,7 +368,7 @@ class DebugFile: dat = fl.read(1) num = unpack('>B', dat)[0] name = self.read_string(fl) - self.arrays[num] = name + self.globals[num] = name def read_array_rec(self, fl): dat = fl.read(2) @@ -416,19 +480,25 @@ class DebugFile: # Begin the work +if (dispatch_dump): + xml.sax.parse(dispatch_dump, DispatchDumpHandler()) + xml.sax.parse(profile_raw, ProfileRawHandler()) source_start = min([ func.addr for func in functions.values() if not func.special ]) -print 'Code segment begins at', hex(source_start) -print len(functions), 'called functions found in', profile_raw +if (not dumb_frotz_mode): + print 'Code segment begins at', hex(source_start) + print len(functions), 'called functions found in', profile_raw if (game_asm): fl = open(game_asm, 'rb') val = fl.read(2) fl.close() - if (val == '\xde\xbf'): + if (not val): + pass + elif (val == '\xde\xbf'): fl = open(game_asm, 'rb') debugfile = DebugFile(fl) fl.close() @@ -454,8 +524,9 @@ if (sourcemap): func.name = funcname func.linenum = linenum - if (badls): - print len(badls), 'functions from', profile_raw, 'did not appear in asm (veneer functions)' + if (not dumb_frotz_mode): + if (badls): + print len(badls), 'functions from', profile_raw, 'did not appear in asm (veneer functions)' function_names = {} for func in functions.values(): @@ -463,11 +534,29 @@ if (sourcemap): if (sourcemap): uncalled_funcs = [ funcname for (addr, (linenum, funcname)) in sourcemap.items() if (addr+source_start) not in functions ] - print len(uncalled_funcs), 'functions found in', game_asm, 'were never called' - -print 'Functions that consumed the most time (excluding children):' -ls = functions.values() -ls.sort(lambda x1, x2: cmp(x2.self_time, x1.self_time)) -for func in ls[:10]: - func.dump() - + if (not dumb_frotz_mode): + print len(uncalled_funcs), 'functions found in', game_asm, 'were never called' + +if (dumb_frotz_mode): + ls = functions.values() + ls.sort(lambda x1, x2: cmp(x2.total_ops, x1.total_ops)) + ops_executed = 0 + routine_calls = 0 + max_stack_use = max([func.max_stack_use for func in ls]) + for func in ls: + if (func.total_ops > ops_executed): + ops_executed = func.total_ops + routine_calls = routine_calls + func.call_count + print 'Total opcodes: %lu' % ops_executed + print 'Total routine calls: %lu' % routine_calls + print 'Max. stack usage: %li' % max_stack_use + print '' + print '%-35s %-10s %-10s %-10s %-4s' % ('Routine', 'Ops', 'Ops(+Subs)', 'Calls', 'Nest') + for func in ls: + func.dump_dumbfrotz_style() +else: + print 'Functions that consumed the most time (excluding children):' + ls = functions.values() + ls.sort(lambda x1, x2: cmp(x2.self_time, x1.self_time)) + for func in ls[:10]: + func.dump() diff --git a/interpreters/glulxe/profile.c b/interpreters/glulxe/profile.c index e7a0810..c871622 100644 --- a/interpreters/glulxe/profile.c +++ b/interpreters/glulxe/profile.c @@ -12,8 +12,11 @@ call stack. In fact, it's downright stupid. @restart, @restore, @restoreundo, or @throw will kill the interpreter. On a normal VM exit (end of top-level routine or @quit), the profiler -writes out a data file called "profile-raw". This is an XML file of -the form +writes out a data file, using the filename you provided with the +"--profile" option. Note that if the VM exits via glk_exit(), or is +interrupted, the data file will be created (empty) but never filled in. + +The data file is an XML file of the form @@ -37,25 +40,33 @@ program's run. Each function tag includes the following attributes: function). self_ops=INT: The number of opcodes executed during all calls to the function, excluding time spent in subcalls. + max_depth=INT: The deepest this function has been nested on the + stack, during any call. + max_stack_use=INT: The greatest number of words on the stack, during + any call. (This is measured when the function returns, so it may + not capture the peak stack usage. If a function never returns, e.g. + Main__(), then this value is approximate.) Note that if a function does not make any function calls, total_time will be the same as self_time (and total_ops the same as self_ops). -Two special function entries may be included. The function with address -"1" (which is not a legal Glulx function address) represents time spent -in @glk opcode calls. This will typically have a large self_time, -because it includes all the time spent waiting for input. +Some of the function entries refer to special interpreter operations. +(These have high addresses, outside the range of normal game files.) +Functions with addresses in the 0xE0000000 range are the interpreter's +output opcodes: @streamchar, @streamunichar, @streamnum, @streamstr. -The function with address "2" represents the time spent printing string -data (the @streamchar, @streamunichar, @streamnum, and @streamstr -opcodes). +Functions with addresses in the 0xF0000000 range are @glk opcode calls. +The number in the lower bits specifies which Glk function was called. +You will always see a large self_time for function 0xF00000C0; this +represents all the time spent waiting for input in glk_select(). -(Both "1" and "2" represent time spent in the Glk library, but they -get there by different code paths.) +(Both the 0xE0000000 and 0xF0000000 entries represent time spent in the +Glk library, but they get there by different code paths.) -The function with the lowest address (ignoring "1" and "2") is the -top-level Main__() function generated by the compiler. Its total_time -is the running time of the entire program. +The function with the lowest address is the top-level Main__() +function generated by the compiler. Its total_time is the running time +of the entire program; its total_ops is the number of opcodes executed +by the entire program; its max_depth is zero. */ @@ -68,6 +79,11 @@ is the running time of the entire program. #include #include +/* Set if the --profile switch is used. */ +static int profiling_active = FALSE; +static char *profiling_filename = NULL; +static strid_t profiling_stream = NULL; + typedef struct function_struct { glui32 addr; @@ -76,6 +92,8 @@ typedef struct function_struct { glui32 entry_depth; struct timeval entry_start_time; glui32 entry_start_op; + glui32 max_depth; + glui32 max_stack_use; struct timeval total_time; glui32 total_ops; struct timeval self_time; @@ -87,6 +105,7 @@ typedef struct function_struct { typedef struct frame_struct { struct frame_struct *parent; function_t *func; + glui32 depth; struct timeval entry_time; glui32 entry_op; @@ -100,12 +119,49 @@ typedef struct frame_struct { static function_t **functions = NULL; static frame_t *current_frame = NULL; +/* This counter is globally visible, because the profile_tick() macro + increments it. */ glui32 profile_opcount = 0; +/* This is called from the setup code -- glkunix_startup_code(), for the + Unix version. If called, the interpreter will keep profiling information, + and write it out at shutdown time. If this is not called, the interpreter + will skip all the profiling code. (Although it won't be quite as fast + as if the VM_PROFILING symbol were compiled out entirely.) + + The arguments are a little tricky, because I developed this on Unix, + but I want it to remain accessible on all platforms. Pass a writable + stream object as the first argument; at game-shutdown time, the terp + will write the profiling data to this object and then close it. + + However, if it's not convenient to open a stream in the startup code, + you can simply pass a filename as the second argument. This filename + will be opened according to the usual Glk data file rules, which means + it may wind up in a sandboxed data directory. The filename should not + contain slashes or other pathname separators. + + If you pass NULL for both arguments, a file called "profile-raw" will + be written. +*/ +void setup_profile(strid_t stream, char *filename) +{ + profiling_active = TRUE; + + if (stream) + profiling_stream = stream; + else if (filename) + profiling_filename = filename; + else + profiling_filename = "profile-raw"; +} + int init_profile() { int bucknum; + if (!profiling_active) + return TRUE; + functions = (function_t **)glulx_malloc(FUNC_HASH_SIZE * sizeof(function_t *)); if (!functions) @@ -143,6 +199,8 @@ static function_t *get_function(glui32 addr) func->total_ops = 0; timerclear(&func->self_time); func->self_ops = 0; + func->max_depth = 0; + func->max_stack_use = 0; } return func; @@ -154,12 +212,15 @@ static char *timeprint(struct timeval *tv, char *buf) return buf; } -void profile_in(glui32 addr, int accel) +void profile_in(glui32 addr, glui32 stackuse, int accel) { frame_t *fra; function_t *func; struct timeval now; + if (!profiling_active) + return; + /* printf("### IN: %lx%s\n", addr, (accel?" accel":"")); */ gettimeofday(&now, NULL); @@ -174,6 +235,9 @@ void profile_in(glui32 addr, int accel) } func->entry_depth += 1; + if (func->max_stack_use < stackuse) + func->max_stack_use = stackuse; + fra = (frame_t *)glulx_malloc(sizeof(frame_t)); if (!fra) fatal_error("Profiler: cannot malloc frame."); @@ -182,6 +246,8 @@ void profile_in(glui32 addr, int accel) fra->parent = current_frame; current_frame = fra; + if (fra->parent) + fra->depth = fra->parent->depth + 1; fra->func = func; fra->entry_time = now; fra->entry_op = profile_opcount; @@ -189,13 +255,16 @@ void profile_in(glui32 addr, int accel) fra->children_ops = 0; } -void profile_out() +void profile_out(glui32 stackuse) { frame_t *fra; function_t *func; struct timeval now, runtime; glui32 runops; + if (!profiling_active) + return; + /* printf("### OUT\n"); */ if (!current_frame) @@ -214,6 +283,11 @@ void profile_out() func->self_ops += runops; func->self_ops -= fra->children_ops; + if (func->max_depth < fra->depth) + func->max_depth = fra->depth; + if (func->max_stack_use < stackuse) + func->max_stack_use = stackuse; + if (fra->parent) { timeradd(&runtime, &fra->parent->children_time, &fra->parent->children_time); fra->parent->children_ops += runops; @@ -245,6 +319,9 @@ void profile_out() void profile_fail(char *reason) { + if (!profiling_active) + return; + fatal_error_2("Profiler: unable to handle operation", reason); } @@ -253,18 +330,28 @@ void profile_quit() int bucknum; function_t *func; char linebuf[512]; - frefid_t profref; strid_t profstr; + if (!profiling_active) + return; + while (current_frame) { - profile_out(); + profile_out(0); } - profref = glk_fileref_create_by_name(fileusage_BinaryMode|fileusage_Data, "profile-raw", 0); - if (!profref) - fatal_error("Profiler: unable to create profile-raw file"); + if (profiling_stream) { + profstr = profiling_stream; + } + else if (profiling_filename) { + frefid_t profref = glk_fileref_create_by_name(fileusage_BinaryMode|fileusage_Data, profiling_filename, 0); + if (!profref) + fatal_error_2("Profiler: unable to create profile output fileref", profiling_filename); - profstr = glk_stream_open_file(profref, filemode_Write, 0); + profstr = glk_stream_open_file(profref, filemode_Write, 0); + } + else { + fatal_error("Profiler: no profile output handle!"); + } glk_put_string_stream(profstr, "\n"); @@ -280,12 +367,13 @@ void profile_quit() func->self_ops, timeprint(&func->self_time, self_buf)); ### */ - sprintf(linebuf, " \n", - func->addr, func->call_count, func->accel_count, - func->total_ops, + sprintf(linebuf, " \n", + (unsigned long)func->addr, (long)func->call_count, (long)func->accel_count, + (long)func->total_ops, timeprint(&func->total_time, total_buf), - func->self_ops, - timeprint(&func->self_time, self_buf)); + (long)func->self_ops, + timeprint(&func->self_time, self_buf), + (long)func->max_depth, (long)func->max_stack_use); glk_put_string_stream(profstr, linebuf); } } @@ -300,6 +388,11 @@ void profile_quit() #else /* VM_PROFILING */ +void setup_profile(strid_t stream, char *filename) +{ + /* Profiling is not compiled in. Do nothing. */ +} + int init_profile() { /* Profiling is not compiled in. Do nothing. */ diff --git a/interpreters/glulxe/search.c b/interpreters/glulxe/search.c index 26bf480..f93dcd4 100644 --- a/interpreters/glulxe/search.c +++ b/interpreters/glulxe/search.c @@ -5,7 +5,6 @@ #include "glk.h" #include "glulxe.h" -#include "opcodes.h" #define serop_KeyIndirect (0x01) #define serop_ZeroKeyTerminates (0x02) diff --git a/interpreters/glulxe/serial.c b/interpreters/glulxe/serial.c index a547652..036cf88 100644 --- a/interpreters/glulxe/serial.c +++ b/interpreters/glulxe/serial.c @@ -35,9 +35,6 @@ static int undo_chain_size = 0; static int undo_chain_num = 0; unsigned char **undo_chain = NULL; -static glui32 protect_pos = 0; -static glui32 protect_len = 0; - static glui32 write_memstate(dest_t *dest); static glui32 write_heapstate(dest_t *dest, int portable); static glui32 write_stackstate(dest_t *dest, int portable); @@ -810,9 +807,8 @@ static glui32 read_heapstate(dest_t *dest, glui32 chunklen, int portable, static glui32 write_stackstate(dest_t *dest, int portable) { - glui32 res, pos; - glui32 val, lx; - unsigned char ch; + glui32 res; + glui32 lx; glui32 lastframe; /* If we're storing for the purpose of undo, we don't need to do any @@ -970,8 +966,7 @@ static glui32 write_stackstate(dest_t *dest, int portable) static glui32 read_stackstate(dest_t *dest, glui32 chunklen, int portable) { - glui32 res, pos; - unsigned char ch; + glui32 res; glui32 frameend, frm, frm2, frm3, locpos, frlen, numlocals; if (chunklen > stacksize) diff --git a/interpreters/glulxe/string.c b/interpreters/glulxe/string.c index b3f119d..f33d311 100644 --- a/interpreters/glulxe/string.c +++ b/interpreters/glulxe/string.c @@ -820,7 +820,7 @@ char *make_temp_string(glui32 addr) { int ix, len; glui32 addr2; - char *res, *cx; + char *res; if (Mem1(addr) != 0xE0) fatal_error("String argument to a Glk call must be unencoded."); @@ -849,7 +849,7 @@ glui32 *make_temp_ustring(glui32 addr) { int ix, len; glui32 addr2; - glui32 *res, *cx; + glui32 *res; if (Mem1(addr) != 0xE2) fatal_error("Ustring argument to a Glk call must be unencoded."); diff --git a/interpreters/glulxe/unixstrt.c b/interpreters/glulxe/unixstrt.c index 2e62f22..38779a2 100644 --- a/interpreters/glulxe/unixstrt.c +++ b/interpreters/glulxe/unixstrt.c @@ -3,14 +3,22 @@ http://eblong.com/zarf/glulx/index.html */ +#include #include "glk.h" #include "glulxe.h" #include "glkstart.h" /* This comes with the Glk library. */ -#include -/* The only command-line argument is the filename. */ +/* The only command-line argument is the filename. And the profiling switch, + if that's compiled in. The only *two* command-line arguments are... +*/ glkunix_argumentlist_t glkunix_arguments[] = { + +#if VM_PROFILING + { "--profile", glkunix_arg_ValueFollows, "Generate profiling information to a file." }, +#endif /* VM_PROFILING */ + { "", glkunix_arg_ValueFollows, "filename: The game file to load." }, + { NULL, glkunix_arg_End, NULL } }; @@ -18,35 +26,64 @@ int glkunix_startup_code(glkunix_startup_t *data) { /* It turns out to be more convenient if we return TRUE from here, even when an error occurs, and display an error in glk_main(). */ - char *cx; + int ix; + char *filename = NULL; unsigned char buf[12]; int res; #ifdef GARGLK - garglk_set_program_name("Glulxe 0.4.6"); - garglk_set_program_info("Glulxe 0.4.6 by Andrew Plotkin"); + char *cx; + garglk_set_program_name("Glulxe 0.4.7"); + garglk_set_program_info("Glulxe 0.4.7 by Andrew Plotkin"); #endif - if (data->argc <= 1) { + /* Parse out the arguments. They've already been checked for validity, + and the library-specific ones stripped out. + As usual for Unix, the zeroth argument is the executable name. */ + for (ix=1; ixargc; ix++) { + +#if VM_PROFILING + if (!strcmp(data->argv[ix], "--profile")) { + ix++; + if (ixargc) { + strid_t profstr = glkunix_stream_open_pathname_gen(data->argv[ix], TRUE, FALSE, 1); + if (!profstr) { + init_err = "Unable to open profile output file."; + init_err2 = data->argv[ix]; + return TRUE; + } + setup_profile(profstr, NULL); + } + continue; + } +#endif /* VM_PROFILING */ + + if (filename) { + init_err = "You must supply exactly one game file."; + return TRUE; + } + filename = data->argv[ix]; + } + + if (!filename) { init_err = "You must supply the name of a game file."; #ifdef GARGLK return TRUE; /* Hack! but I want error message in glk window */ #endif return FALSE; } - cx = data->argv[1]; - gamefile = glkunix_stream_open_pathname(cx, FALSE, 1); + gamefile = glkunix_stream_open_pathname(filename, FALSE, 1); if (!gamefile) { init_err = "The game file could not be opened."; - init_err2 = cx; + init_err2 = filename; return TRUE; } #ifdef GARGLK - cx = strrchr(data->argv[1], '/'); - if (!cx) cx = strrchr(data->argv[1], '\\'); - garglk_set_story_name(cx ? cx + 1 : data->argv[1]); + cx = strrchr(filename, '/'); + if (!cx) cx = strrchr(filename, '\\'); + garglk_set_story_name(cx ? cx + 1 : filename); #endif /* Now we have to check to see if it's a Blorb file. */ -- 2.30.2