Update Glulxe to 0.4.7
authorPhilip Chimento <philip.chimento@gmail.com>
Sat, 11 Feb 2012 23:33:39 +0000 (00:33 +0100)
committerPhilip Chimento <philip.chimento@gmail.com>
Sat, 11 Feb 2012 23:52:54 +0000 (00:52 +0100)
13 files changed:
interpreters/glulxe/README
interpreters/glulxe/exec.c
interpreters/glulxe/funcs.c
interpreters/glulxe/gestalt.c
interpreters/glulxe/glkop.c
interpreters/glulxe/glulxe.h
interpreters/glulxe/heap.c
interpreters/glulxe/profile-analyze.py
interpreters/glulxe/profile.c
interpreters/glulxe/search.c
interpreters/glulxe/serial.c
interpreters/glulxe/string.c
interpreters/glulxe/unixstrt.c

index e903d1e7e4fdbe8841ebd1c8c1819fdbeeaa0ca1..952e8dd888c34cc04268660b3b74323918984ea5 100644 (file)
@@ -1,5 +1,5 @@
 Glulxe: the Glulx VM interpreter
-Version 0.4.###
+Version 0.4.7
 
     Designed by Andrew Plotkin <erkyrath@eblong.com>
     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.
index 4dd3fcdc757d7c36f9e5159b11088bbe766f13c6..af69189b4cf2ef85ec7294d2e965b8b39653821c 100644 (file)
@@ -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:
index c0aac4dccae22643c1e6ec4b91aeb2aa19c98af6..2e03ccdb3551d78e3a3539e0c7799d1547585786 100644 (file)
@@ -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():
index 87a8182e713f6ca5d13df12681d5bae1028c853f..7f6418d03364c72900418ac89f2baf77a299c93e 100644 (file)
@@ -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
index e761cd73f49a31edf672c3f652449f4f1cf6497d..090632abdcbfabf5cb6ba83e6662b094723b34ac 100644 (file)
@@ -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)
 {
index 72308a650c6bd5510470202cd4d6a245ed536888..64a9f7f4128618472951e40e6132c45605d67bce 100644 (file)
@@ -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 */
index ea5bf24afa8e914d604b04b4d3e1ccce49e91fa4..d025fb5c36813d557140b9b8974372da40a19415 100644 (file)
@@ -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;
index c7f7345ab26cc118949ffdb4f0d7ccbbb0ebf6fe..ae2b2fb04c046b145ca546166662c583c1b9af71 100644 (file)
@@ -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 '<Function $' + self.hexaddr + ' ' + repr(self.name) + '>'
@@ -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()
index e7a0810968812b240b2c99c5e755c8651d277d78..c8716221fb0e54608b1cc0cbebf69b0a9b4d63c1 100644 (file)
@@ -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
 
 <profile>
   <function ... />
@@ -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 <string.h>
 #include <sys/time.h>
 
+/* 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, "<profile>\n");
 
@@ -280,12 +367,13 @@ void profile_quit()
         func->self_ops,
         timeprint(&func->self_time, self_buf));
       ### */
-      sprintf(linebuf, "  <function addr=\"%lx\" call_count=\"%ld\" accel_count=\"%ld\" total_ops=\"%ld\" total_time=\"%s\" self_ops=\"%ld\" self_time=\"%s\" />\n",
-        func->addr, func->call_count, func->accel_count,
-        func->total_ops,
+      sprintf(linebuf, "  <function addr=\"%lx\" call_count=\"%ld\" accel_count=\"%ld\" total_ops=\"%ld\" total_time=\"%s\" self_ops=\"%ld\" self_time=\"%s\" max_depth=\"%ld\" max_stack_use=\"%ld\" />\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. */
index 26bf480120ee6f697226f27a34ab8bbd2832fd98..f93dcd409fc36de77d6b5823a34373340c41e379 100644 (file)
@@ -5,7 +5,6 @@
 
 #include "glk.h"
 #include "glulxe.h"
-#include "opcodes.h"
 
 #define serop_KeyIndirect (0x01)
 #define serop_ZeroKeyTerminates (0x02)
index a547652a688a181c85f77a3f6a9972cb142ece34..036cf88b33b4b5f4f99bcf917340db3dba994d6a 100644 (file)
@@ -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)
index b3f119dc3dcaa2d9d0e5dda4c3f345682ffe52db..f33d311e415f71d2e115e56a42e8752a160ecaaa 100644 (file)
@@ -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.");
index 2e62f22eace4e9d0e1182c796a432b0bf19de615..38779a2d788443d4e8eb1bed9c4cfbad0ea201d5 100644 (file)
@@ -3,14 +3,22 @@
     http://eblong.com/zarf/glulx/index.html
 */
 
+#include <string.h>
 #include "glk.h"
 #include "glulxe.h"
 #include "glkstart.h" /* This comes with the Glk library. */
-#include <string.h>
 
-/* 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; ix<data->argc; ix++) {
+
+#if VM_PROFILING
+    if (!strcmp(data->argv[ix], "--profile")) {
+      ix++;
+      if (ix<data->argc) {
+        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. */