test: Yet another pass at synchronization logic

With the new alpha-shifting logic, the test suite runs much faster
than before, and as a result, ran into many more synchronization issues.

Ensure that we wait for the stack to actually update before we
proceed with evaluating its content. This required a change in logic
where we expect the stack to actually change value, so some tests
have to be changed accordingly.

The net result is that the tests can now pass reliably at full speed.

Fixes: #77

Signed-off-by: Christophe de Dinechin <christophe@dinechin.org>
This commit is contained in:
Christophe de Dinechin 2023-07-16 15:44:01 +02:00
parent b5dd83a692
commit 17160f891b
6 changed files with 138 additions and 56 deletions

View file

@ -54,6 +54,7 @@ RECORDER(dmcp_notyet, 64, "DMCP features that are not yet implemented");
RECORDER(keys, 64, "DMCP key handling");
RECORDER(keys_warning, 64, "Warnings related to key handling");
RECORDER(lcd, 64, "DMCP lcd/display functions");
RECORDER(lcd_refresh, 64, "DMCP lcd/display refresh");
RECORDER(lcd_width, 64, "Width of strings and chars");
RECORDER(lcd_warning, 64, "Warnings from lcd/display functions");
@ -202,13 +203,18 @@ int handle_menu(const smenu_t * menu_id, int action, int cur_line)
return 0;
}
int8_t keys[4] = { 0 };
uint keyrd = 0;
uint keywr = 0;
enum { nkeys = sizeof(keys) };
volatile int8_t keys[4] = { 0 };
volatile uint keyrd = 0;
volatile uint keywr = 0;
enum { nkeys = sizeof(keys) / sizeof(keys[0]) };
int key_empty()
{
record(keys,
"Key empty %u-%u = %+s",
keyrd,
keywr,
keyrd == keywr ? "empty" : "full");
return keyrd == keywr;
}
@ -221,7 +227,7 @@ int key_pop()
{
if (keyrd != keywr)
{
record(keys, "Key %d (rd %u wr %u)", keys[keyrd], keyrd, keywr);
record(keys, "Key %d (rd %u wr %u)", keys[keyrd % nkeys], keyrd, keywr);
return keys[keyrd++ % nkeys];
}
return -1;
@ -256,6 +262,7 @@ int key_push(int k)
keys[keywr++ % nkeys] = k;
else
record(keys_warning, "Dropped key %d (wr %u rd %u)", k, keywr, keyrd);
record(keys, "Pushed key %d (wr %u rd %u)", k, keywr, keyrd);
return keywr - keyrd < nkeys;
}
int read_key(int *k1, int *k2)
@ -470,22 +477,23 @@ void lcd_forced_refresh()
}
void lcd_refresh()
{
record(lcd, "Refresh");
record(lcd_refresh, "Refresh %u", lcd_needsupdate);
lcd_needsupdate++;
}
void lcd_refresh_dma()
{
record(lcd, "Refresh DMA");
record(lcd_refresh, "Refresh DMA %u", lcd_needsupdate);
lcd_needsupdate++;
}
void lcd_refresh_wait()
{
record(lcd, "Refresh Wait");
record(lcd_refresh, "Refresh wait %u", lcd_needsupdate);
lcd_needsupdate++;
}
void lcd_refresh_lines(int ln, int cnt)
{
record(lcd, "Refresh lines (%d-%d) count %d", ln, ln+cnt-1, cnt);
record(lcd_refresh, "Refresh lines %u (%d-%d) count %d",
lcd_needsupdate, ln, ln+cnt-1, cnt);
lcd_needsupdate += (ln >= 0 && cnt > 0);
}
void lcd_setLine(disp_stat_t * ds, int ln_nr)

View file

@ -40,6 +40,7 @@
#include "sysmenu.h"
#include "target.h"
#include "util.h"
#include "recorder.h"
#include <algorithm>
#include <cctype>
@ -54,6 +55,9 @@ using std::min;
uint last_keystroke_time = 0;
int last_key = 0;
RECORDER(main, 16, "Main RPL thread");
static void redraw_lcd()
// ----------------------------------------------------------------------------
@ -63,6 +67,8 @@ static void redraw_lcd()
uint period = 60000;
uint now = sys_current_ms();
record(main, "Begin redraw at %u", now);
// Draw the header
Screen.fill(0, 0, LCD_W, HeaderFont->height() + 1, pattern::black);
Screen.text(4, 0, utf8(PROGRAM_NAME), HeaderFont, pattern::white);
@ -81,6 +87,9 @@ static void redraw_lcd()
ui.draw_error();
// Refresh the screen
uint then = sys_current_ms();
record(main,
"Refresh at %u (%u later), period %u", then, then - now, period);
lcd_refresh_lines(0, LCD_H);
// Refresh screen moving elements after 0.1s
@ -99,6 +108,7 @@ static void redraw_periodics()
uint dawdle_time = now - last_keystroke_time;
bool dawdling = dawdle_time > 10000;
record(main, "Periodics %u", now);
int cy = ui.draw_cursor(now, period, false);
if (cy >= 0)
lcd_refresh_lines(cy, EditorFont->height());
@ -117,6 +127,9 @@ static void redraw_periodics()
else if (dawdle_time > 10000) // If inactive for 10 seconds
period = 3000; // Only upate screen every 3 second
uint then = sys_current_ms();
record(main, "Dawdling for %u at %u after %u", period, then, then-now);
// Refresh screen moving elements after 0.1s
sys_timer_start(TIMER1, period);
}
@ -284,6 +297,7 @@ extern "C" void program_main()
reset_auto_off();
key = key_pop();
hadKey = true;
record(main, "Got key %d", key);
#if SIMULATOR
if (key == -1)
{
@ -297,12 +311,25 @@ extern "C" void program_main()
}
bool repeating = sys_timer_timeout(TIMER0);
if (repeating)
{
hadKey = true;
record(main, "Repeating key %d", key);
}
// Fetch the key (<0: no key event, >0: key pressed, 0: key released)
record(main, "Testing key %d (%+s)", key, hadKey ? "had" : "nope");
if (key >= 0 && hadKey)
{
#if SIMULATOR
if (key > 0)
last_key = key;
else if (last_key > 0)
last_key = -last_key;
#endif
record(main, "Handle key %d last %d", key, last_key);
handle_key(key, repeating);
record(main, "Did key %d last %d", key, last_key);
// Redraw the LCD unless there is some type-ahead
if (key_empty())
@ -310,6 +337,7 @@ extern "C" void program_main()
// Record the last keystroke
last_keystroke_time = sys_current_ms();
record(main, "Last keystroke time %u", last_keystroke_time);
}
else
{
@ -333,7 +361,16 @@ bool program::interrupted()
{
if (key_tail() == KEY_EXIT)
return true;
#if SIMULATOR
int key = key_pop();
record(main, "Runner popped key %d, last=%d", key, last_key);
if (key > 0)
last_key = key;
else if (last_key > 0)
last_key = -last_key;
#else
key_pop();
#endif
}
return false;
}

View file

@ -103,8 +103,9 @@ void stack::draw_stack()
char buf[8];
coord y = bottom;
#ifdef SIMULATOR
extern int last_key;
if (depth == 0)
output(object::ID_object, nullptr, 0);
output(last_key, object::ID_object, nullptr, 0);
#endif
for (uint level = 0; level < depth; level++)
{
@ -128,9 +129,10 @@ void stack::draw_stack()
#ifdef SIMULATOR
if (level == 0)
{
output(obj->type(), out, len);
output(last_key, obj->type(), out, len);
record(tests,
"X-reg %+s size %u %s", object::name(obj->type()), len, out);
"Key %d X-reg %+s size %u %s",
last_key, object::name(obj->type()), len, out);
}
#endif

View file

@ -51,13 +51,18 @@ public:
// Record the output of the stack for testing purpose
// ------------------------------------------------------------------------
{
int key;
object::id type;
std::string output;
} history[8];
void output(object::id type, utf8 stack0, size_t len)
enum { COUNT = sizeof(history) / sizeof(*history) };
void output(int key, object::id type, utf8 stack0, size_t len)
{
data *ptr = history + writer % (sizeof(history) / sizeof(*history));
data *ptr = history + writer % COUNT;
std::string out = std::string(cstring(stack0), len);
ptr->key = key;
ptr->type = type;
ptr->output = std::string(cstring(stack0), len);
writer++;
@ -84,6 +89,14 @@ public:
return ptr->type;
}
int key()
{
if (reader >= writer)
return -99999;
data *ptr = history + reader % (sizeof(history) / sizeof(*history));
return ptr->key;
}
void consume()
{
reader++;

View file

@ -43,7 +43,7 @@ extern volatile int lcd_needsupdate;
RECORDER_DECLARE(errors);
uint wait_time = 10;
uint wait_time = 200;
uint delay_time = 2;
void tests::run(bool onlyCurrent)
@ -91,7 +91,6 @@ void tests::current()
// Test the current thing (this is a temporary test)
// ----------------------------------------------------------------------------
{
complex_functions();
}
@ -301,8 +300,12 @@ void tests::data_types()
cstring eqn = "'X+1'";
test(CLEAR, XEQ, X, ENTER, KEY1, ADD).type(object::ID_equation).expect(eqn);
cstring eqn2 = "'sin(X+1)'";
test(SIN).type(object::ID_equation).expect(eqn2);
test(DOWN, ENTER).type(object::ID_equation).expect(eqn2);
test(SIN)
.type(object::ID_equation).expect(eqn2);
test(DOWN)
.editor(eqn2);
test(ENTER, 1, ADD).
type(object::ID_equation).expect("'sin(X+1)+1'");
step("Equation parsing and simplification");
test(CLEAR, "'(((A))+(B))-(C+D)'", ENTER)
.type(object::ID_equation)
@ -310,25 +313,26 @@ void tests::data_types()
step("equation fancy rendering");
test(CLEAR, XEQ, X, ENTER, INV,
XEQ, Y, ENTER, SHIFT, SQRT, XEQ, Z, ENTER,
"CUBED", ENTER, ADD, ADD)
"CUBED", ENTER, ADD, ADD, WAIT(100))
.type(object::ID_equation)
.expect("'X⁻¹+(Y²+Z³)'");
step("Equation fancy parsing from editor");
test(DOWN, " ", ENTER).type(object::ID_equation).expect("'X⁻¹+(Y²+Z³)'");
test(DOWN, " ", SHIFT, SHIFT, DOWN, " 1 +", ENTER)
.type(object::ID_equation).expect("'X⁻¹+(Y²+Z³)+1'");
step("Fractions");
test(CLEAR, "1/3", ENTER).type(object::ID_fraction).expect("1/3");
test(CLEAR, "20/60", ENTER).type(object::ID_fraction).expect("1/3");
test(CLEAR, "-80/60", ENTER).type(object::ID_neg_fraction).expect("-4/3");
test(CLEAR, "20/60", ENTER).type(object::ID_fraction).expect("1/3");
step("Large integers");
cstring b = "123456789012345678901234567890123456789012345678901234567890";
cstring mb =
"-123456789012345678901234567890123456789012345678901234567890";
test(CLEAR, b, ENTER).type(object::ID_bignum).expect(b);
test(DOWN, ENTER).type(object::ID_bignum).expect(b);
test(CHS).type(object::ID_neg_bignum).expect(mb);
test(DOWN, ENTER).type(object::ID_neg_bignum).expect(mb);
test(DOWN, CHS, ENTER).type(object::ID_neg_bignum).expect(mb);
test(CHS).type(object::ID_bignum).expect(b);
test(DOWN, CHS, ENTER).type(object::ID_neg_bignum).expect(mb);
step("Large fractions");
cstring bf =
@ -338,9 +342,10 @@ void tests::data_types()
"-123456789012345678901234567890123456789012345678901234567890/"
"123456789012345678901234567890123456789012345678901234567891";
test(CLEAR, bf, ENTER).type(object::ID_big_fraction).expect(bf);
test(DOWN, ENTER).type(object::ID_big_fraction).expect(bf);
test(DOWN, CHS, ENTER).type(object::ID_neg_big_fraction).expect(mbf);
test(CHS).type(object::ID_big_fraction).expect(bf);
test(CHS).type(object::ID_neg_big_fraction).expect(mbf);
test(DOWN, ENTER).type(object::ID_neg_big_fraction).expect(mbf);
test(DOWN, CHS, ENTER).type(object::ID_big_fraction).expect(bf);
clear();
}
@ -424,11 +429,11 @@ void tests::arithmetic()
}
step("Integer multiplication");
test(CLEAR, 1, ENTER, 1, MUL).type(object::ID_integer).expect("1");
test(3, MUL).type(object::ID_integer).expect("3");
test(-3, MUL).type(object::ID_neg_integer).expect("-9");
test(2, MUL).type(object::ID_neg_integer).expect("-18");
test(-7, MUL).type(object::ID_integer).expect("126");
test(CLEAR, 3, ENTER, 7, MUL).type(object::ID_integer).expect("21");
test(3, MUL).type(object::ID_integer).expect("63");
test(-3, MUL).type(object::ID_neg_integer).expect("-189");
test(2, MUL).type(object::ID_neg_integer).expect("-378");
test(-7, MUL).type(object::ID_integer).expect("2646");
step("Multiplying ten small integers at random");
for (int i = 0; i < 10; i++)
@ -463,21 +468,20 @@ void tests::arithmetic()
step("Manual computation of 100!");
test(CLEAR, 1, ENTER);
for (uint i = 1; i <= 100; i++)
test(i, MUL);
wait(100); // Takes its sweet time to display (GC?)
test(i, MUL, NOKEYS, WAIT(20));
expect(
"9332621544394415268169923885626670049071596826438162146859296389521"
"7599993229915608941463976156518286253697920827223758251185210916864"
"000000000000000000000000");
step("Manual division by all factors of 100!");
for (uint i = 1; i <= 100; i++)
test(i * 997 % 101, DIV);
test(i * 997 % 101, DIV, NOKEYS, WAIT(20));
expect(1);
step("Manual computation of 997/100!");
test(CLEAR, 997, ENTER);
for (uint i = 1; i <= 100; i++)
test(i * 997 % 101, DIV);
test(i * 997 % 101, DIV, NOKEYS, WAIT(20));
expect(
"997/"
"9332621544394415268169923885626670049071596826438162146859296389521"
@ -498,7 +502,7 @@ void tests::global_variables()
test(XEQ, "A", ENTER).expect("'A'");
test(STO).noerr();
step("Recall global variable");
test(CLEAR, XEQ, "A", ENTER).expect("'A'");
test(CLEAR, 1, ENTER, XEQ, "A", ENTER).expect("'A'");
test("RCL", ENTER).noerr().expect(12345);
step("Store in long-name global variable");
@ -1096,7 +1100,7 @@ void tests::integer_numerical_functions()
.test("cubed", ENTER).expect("-19683");
step("abs")
.test(CLEAR, "-3 abs", ENTER).expect("3")
.test("abs", ENTER).expect("3");
.test("abs", ENTER, 1, ADD).expect("4");
step("norm").test("-5 norm", ENTER).expect("5");
}
@ -1124,7 +1128,7 @@ void tests::decimal_numerical_functions()
.test("cubed", ENTER).expect("-19683");
step("abs")
.test(CLEAR, "-3.21 abs", ENTER).expect("3.21")
.test("abs", ENTER).expect("3.21");
.test("abs", ENTER, 1, ADD).expect("4.21");
#define TFN(name, result) \
step(#name).test(CLEAR, "0.321 " #name, ENTER).expect(result);
@ -1153,8 +1157,8 @@ void tests::decimal_numerical_functions()
TFN(erf, "3.5014422082002382355⁳⁻¹");
TFN(erfc, "6.4985577917997617645⁳⁻¹");
TFN(tgamma, "2.786634540845472368");
TFN(gamma, "2.786634540845472368");
TFN(lgamma, "1.0248346099573131987");
TFN(gamma, "2.786634540845472368");
TFN(cbrt, "6.8470212775722416184⁳⁻¹");
TFN(norm, "0.321");
#undef TFN
@ -1199,7 +1203,7 @@ void tests::complex_types()
test(CLEAR, "0∡0", ENTER)
.type(object::ID_polar).expect("0∡0");
test(CLEAR, "1∡90", ENTER)
.type(object::ID_polar).expect("1∡90");
.type(object::ID_polar).expect("1∡2.0354056994857893230");
test(CLEAR, "-1∡0", ENTER)
.type(object::ID_polar).expect("1∡3.1415926535897932385");
@ -1426,7 +1430,6 @@ tests &tests::istep(cstring name)
// ----------------------------------------------------------------------------
{
record(tests, "Step %+s, catching up", name);
Stack.catch_up();
sname = name;
if (sindex++)
{
@ -1552,9 +1555,6 @@ tests &tests::itest(tests::key k, bool release)
{
extern int key_remaining();
// Catch up with stack output
Stack.catch_up();
// Check for special key sequences
switch (k)
{
@ -1580,7 +1580,10 @@ tests &tests::itest(tests::key k, bool release)
while (!key_empty())
sys_delay(delay_time);
record(tests, "Push key %d update %u->%u last %d", k, lcd_update, lcd_needsupdate, last_key);
lcd_update = lcd_needsupdate;
Stack.catch_up();
last_key = k;
key_push(k);
if (longpress)
{
@ -1594,6 +1597,10 @@ tests &tests::itest(tests::key k, bool release)
{
while (!key_remaining())
sys_delay(delay_time);
record(tests, "Release key %d update %u->%u last %d", k, lcd_update, lcd_needsupdate, last_key);
lcd_update = lcd_needsupdate;
Stack.catch_up();
last_key = -k;
key_push(RELEASE);
}
@ -1937,10 +1944,7 @@ tests &tests::nokeys()
// ----------------------------------------------------------------------------
{
while (!key_empty())
{
Stack.catch_up();
sys_delay(delay_time);
}
return *this;
}
@ -1950,23 +1954,40 @@ tests &tests::refreshed()
// Wait until the screen was updated by the calculator
// ----------------------------------------------------------------------------
{
record(tests, "Waiting for refresh");
// Wait for a screen redraw
record(tests, "Waiting for screen update");
while (lcd_needsupdate == lcd_update)
sys_delay(delay_time);
// Wait for a stack update
uint32_t start = sys_current_ms();
while (!Stack.available() && sys_current_ms() - start < wait_time)
sys_delay(delay_time);
// Check that we have latest stack update
while (Stack.available() > 1)
Stack.consume();
record(tests, "Waiting for key %d in stack at %u", last_key, start);
while (sys_current_ms() - start < wait_time)
{
if (!Stack.available())
{
sys_delay(delay_time);
}
else if (Stack.available() > 1)
{
record(tests, "Consume extra stack");
Stack.consume();
}
else if (Stack.key() == last_key)
{
record(tests, "Consume extra stack");
break;
}
else
{
record(tests, "Wrong key %d", Stack.key());
Stack.consume();
}
}
record(tests,
"Refreshed, needs=%u update=%u available=%u",
"Refreshed, key %d, needs=%u update=%u available=%u",
Stack.key(),
lcd_needsupdate,
lcd_update,
Stack.available());

View file

@ -307,6 +307,7 @@ protected:
uint count;
uint refresh;
int lcd_update;
int last_key;
bool ok;
bool longpress;
std::vector<failure> failures;