tests: Occasional corruption of test output

[c3d]

tests: Occasional corruption of test output

[c3d]

Debug session:

(lldb) up
up
frame #1: 0x00000001002a76c8 db48x`tests::expect(char const*, unsigned int) + 588 at /Users/ddd/Work/calc/db48x/src/tests.cc:9511
   9508	                return *this;
   9509	            explain("Expected output [", output, "], "
   9510	                    "got [", cstring(out), "] instead");
-> 9511	            return fail();
    	                   ^
   9512	        }
   9513	        sys_delay(refresh_delay_time);
   9514	    }
(lldb) p out
p out
(utf8) 0x000000014039d880 "'cos(0·A+A+A)+cos(0·B+B+B+B)+sin(0·C+C+C+C+\xff)'"

The corruption is a 0xff in the buffer output

(lldb) p rt.stack(0)
p rt.stack(0)
(object_p) 0x000000010f123056
(lldb) d rt.stack(0)
d rt.stack(0)
(cstring) 0x000000010f12513f "'cos(0·A+A+A)+cos(0·B+B+B+B)+sin(0·C+C+C+C+C)'"

The original object is correct, so the corruption is only in the rendering of the stack for the test harness.

(lldb) p Stack
p Stack
(stack) {
  interactive = 0
  interactive_base = 0
  history = {
    [0] = (key = -1, type = ID_expression, output = "'cos(2·A)+cos(3·B)+sin(4·C)'")
    [1] = (key = -24, type = ID_expression, output = "'cos(2·A)+cos(3·B)+sin(4·C)'")
    [2] = (key = -3, type = ID_expression, output = "'cos(2·A)+cos(3·B)+sin(4·C)'")
    [3] = (key = -8, type = ID_expression, output = "'cos(2·A)+cos(3·B)+sin(4·C)'")
    [4] = (key = -13, type = ID_integer, output = "9")
    [5] = (key = -13, type = ID_integer, output = "9")
    [6] = (key = -17, type = ID_expression, output = "'cos(0·A+A+A)+cos(0·B+B+B+B)+sin(0·C+C+C+C+C)'")
    [7] = (key = -17, type = ID_expression, output = "'cos(0·A+A+A)+cos(0·B+B+B+B)+sin(0·C+C+C+C+\xff)'")
  }
  writer = 14200
  reader = 14199
}

The output is corrupt after getting the correct result, so it's not the rewrite engine messing up. But garbage collection apparently is part of the problem:

(lldb) p recorder_dump()
p recorder_dump()
[155 0.000309] recorder: Activating tweak 'est_graphics' (0x10043ceb8)
[156 0.000309] recorder: Activating tweak 'est_help' (0x10043ced8)
[...]
[80634646 367.315079] gc_details: Move 0x10f12360d to 0x10f12362d size 0, scratch
[80634648 367.315079] gc_details: Move 0x10f12362d to 0x10f12365e size 0, scratch
[80634649 367.315083] tests_rpl: Key -17 X-reg expression size 49 0x10f12365e
[80634660 367.315103] gc_details: Move 0x10f12365e to 0x10f1236a9 size 1, scratch
[80634661 367.315103] gc_details: Adjusting GC-safe 0x1702e3680 from 0x10f12365e to 0x10f1236a9
[80634667 367.315109] gc_details: Move 0x10f1236a9 to 0x10f123718 size 0, scratch
[...]
[80635129 16112.283802] runtime: Initializing object 0x10f12510e type 10 size 49
[80635130 16112.283802] gc_details: Move 0x10f12510e to 0x10f12513f size 0, scratch
[80635131 16605.119513] recorder: Recorder dump
(unsigned int) 2042
(lldb) x 0x10f12365e
x 0x10f12365e
0x10f12365e: 2a 0f 24 fe ff fe ff fe ff fe ff fe ff 1e f8 0e  *.$.............
0x10f12366e: f0 06 e0 02 c0 c6 c3 ee c7 ee 87 fe 8f fe 8f fe  ................
(lldb)

So it's just a sync problem between garbage collector and the testing thread copying the data. Not really a biggie, will not happen when not running a test.