Refactor cursor_debug output a bit to allow some simple profiling.

src/PAST/Compiler-Regex.pir

@@ -150,20 +150,20 @@ Return the POST representation of the regex AST rooted by C<node>.
     ops.'push_pirop'('substr', tgt, tgt, off, 'result'=>tgt)
     ops.'push'(startlabel)
     ops.'push_pirop'('eq', '$I10', 1, restartlabel)
-    self.'!cursorop'(ops, '!cursor_debug', 0, '"START "', regexname_esc)
+    self.'!cursorop'(ops, '!cursor_debug', 0, '"START"', regexname_esc)
 
     $P0 = self.'post_regex'(node)
     ops.'push'($P0)
     ops.'push'(restartlabel)
-    self.'!cursorop'(ops, '!cursor_debug', 0, '"NEXT "', regexname_esc)
+    self.'!cursorop'(ops, '!cursor_debug', 0, '"NEXT"', regexname_esc)
     ops.'push'(faillabel)
     self.'!cursorop'(ops, '!mark_fail', 4, rep, pos, '$I10', '$P10', 0)
     ops.'push_pirop'('lt', pos, CURSOR_FAIL, donelabel)
     ops.'push_pirop'('eq', pos, CURSOR_FAIL, faillabel)
     ops.'push_pirop'('jump', '$I10')
     ops.'push'(donelabel)
     self.'!cursorop'(ops, '!cursor_fail', 0)
-    self.'!cursorop'(ops, '!cursor_debug', 0, '"FAIL  "', regexname_esc)
+    self.'!cursorop'(ops, '!cursor_debug', 0, '"FAIL"', regexname_esc)
     ops.'push_pirop'('return', cur)
     .return (ops)
 .end
@@ -831,7 +831,7 @@ second child of this node.
 
     ops.'push_pirop'('inline', 'inline'=>'  # rx pass')
     self.'!cursorop'(ops, '!cursor_pass', 0, pos, regexname)
-    self.'!cursorop'(ops, '!cursor_debug', 0, '"PASS  "', regexname, '" at pos="', pos)
+    self.'!cursorop'(ops, '!cursor_debug', 0, '"PASS"', regexname, '" at pos="', pos)
 
     .local string backtrack
     backtrack = node.'backtrack'()

src/Regex/Cursor-protoregex-peek.pir

@@ -29,7 +29,7 @@ Perform a match for protoregex C<name>.
   have_tokrx:
 
     if null debug goto debug_skip_1
-    self.'!cursor_debug'('PROTO ', name)
+    self.'!cursor_debug'('PROTO', name)
   debug_skip_1:
 
     # If there are no entries at all for this protoregex, we fail outright.
@@ -52,7 +52,7 @@ Perform a match for protoregex C<name>.
     if null debug goto debug_skip_2
     $S0 = escape token
     $S1 = escape token1
-    self.'!cursor_debug'('        token1="', $S1, '", token="', $S0, '"')
+    self.'!cursor_debug'('NOTE', 'token1="', $S1, '", token="', $S0, '"')
   debug_skip_2:
 
     # Create a hash to keep track of the methods we've already called,
@@ -101,14 +101,14 @@ Perform a match for protoregex C<name>.
     pos = result.'pos'()
 
     if null debug goto debug_skip_3
-    self.'!cursor_debug'('PASS  ', name, ' at pos=', pos)
+    self.'!cursor_debug'('PASS', name, ' at pos=', pos)
   debug_skip_3:
 
     .return (result)
 
   fail:
     if null debug goto debug_skip_4
-    self.'!cursor_debug'('FAIL  ', name)
+    self.'!cursor_debug'('FAIL', name)
   debug_skip_4:
     unless null result goto fail_1
     result = self.'!cursor_start'()
@@ -173,7 +173,7 @@ create a new one and return it.
     toklen = prototable[$S0]
     unless null tokrx goto tokrx_done
 
-    self.'!cursor_debug'('Generating protoregex table for ', name)
+    self.'!cursor_debug'('NOTE','Generating protoregex table for ', name)
 
     .local pmc toklen, tokrx
     toklen = new ['Hash']

src/Regex/Cursor.pir

@@ -473,22 +473,27 @@ Log a debug message.
 =cut
 
 .sub '!cursor_debug' :method
+    .param string tag
     .param pmc args            :slurpy
     $P0 = getattribute self, '$!debug'
     if null $P0 goto done
     unless $P0 goto done
-    .local pmc from, pos, orig
-    .local int line
+    .local pmc fmt, from, pos, orig, line
+    fmt = new ['ResizablePMCArray']
     from = getattribute self, '$!from'
     orig = getattribute self, '$!target'
     line = orig.'lineof'(from)
-    inc line
+
     $P0 = getinterp
     $P1 = $P0.'stdhandle'(2)
-    print $P1, from
-    print $P1, '/'
-    print $P1, line
-    print $P1, ': '
+
+    $N0 = time
+    push fmt, $N0
+    push fmt, from
+    push fmt, line
+    push fmt, tag
+    $S0 = sprintf "%.6f %d/%d %-8s ", fmt
+    print $P1, $S0
     $S0 = join '', args
     print $P1, $S0
     print $P1, "\n"

src/cheats/hll-grammar.pir

@@ -657,7 +657,7 @@ An operator precedence parser.
 
     .local pmc pos
     pos = self.'pos'()
-    self.'!cursor_debug'('START MARKER name=', markname, ', pos=', pos)
+    self.'!cursor_debug'('START', 'MARKER name=', markname, ', pos=', pos)
 
     .local pmc markhash
     markhash = get_global '%!MARKHASH'
@@ -666,15 +666,15 @@ An operator precedence parser.
     set_global '%!MARKHASH', markhash
   have_markhash:
     markhash[markname] = pos
-    self.'!cursor_debug'('PASS  MARKER')
+    self.'!cursor_debug'('PASS', 'MARKER')
     .return (1)
 .end
 
 
 .sub 'MARKED' :method
     .param pmc markname
 
-    self.'!cursor_debug'('START MARKED name=', markname)
+    self.'!cursor_debug'('START','MARKED name=', markname)
 
     .local pmc markhash
     markhash = get_global '%!MARKHASH'
@@ -683,10 +683,10 @@ An operator precedence parser.
     if null $P0 goto fail
     $P1 = self.'pos'()
     unless $P0 == $P1 goto fail
-    self.'!cursor_debug'('PASS  MARKED')
+    self.'!cursor_debug'('PASS','MARKED')
     .return (1)
   fail:
-    self.'!cursor_debug'('FAIL  MARKED')
+    self.'!cursor_debug'('FAIL','MARKED')
     .return (0)
 .end