fixup single-step test

This commit is an attempt to fix the test failure here:
<http://buildbot2.highlab.com/buildbot/#/builders/11/builds/990/steps/13/logs/stdio>

I believe the test failure is due to a race condition in the test script,
not a bug in LinuxCNC.

Before this commit, the test requests a step any time the machine X
and Y positions are both very near an integer multiple of 5.  The test
failure linked above shows this in the log:

    Taking step from X30.00 Y30.00
    line=9; Xpos=30.98; Ypos=30.00; Zpos=0.00; counter=25
    line=9; Xpos=31.82; Ypos=30.00; Zpos=0.00; counter=25
    line=9; Xpos=32.65; Ypos=30.00; Zpos=0.00; counter=25
    line=9; Xpos=33.48; Ypos=30.00; Zpos=0.00; counter=25
    line=9; Xpos=34.32; Ypos=30.00; Zpos=0.00; counter=25
    task: main loop took 0.015550 seconds
    Taking step from X35.00 Y30.00
    line=9; Xpos=35.00; Ypos=30.00; Zpos=0.00; counter=25
    Taking step from X35.00 Y30.00
    line=0; Xpos=35.00; Ypos=30.00; Zpos=0.00; counter=25
    Taking step from X35.00 Y30.00
    line=9; Xpos=35.00; Ypos=30.00; Zpos=0.00; counter=25
    Taking step from X35.00 Y30.00
    line=5; Xpos=34.02; Ypos=30.00; Zpos=0.00; counter=0
    line=5; Xpos=33.19; Ypos=30.00; Zpos=0.00; counter=0
    ...
    End counter incorrect:  5 != 25

Normally the test would stop at (X=35, Y=30) with counter=25, and the
test would pass.

I believe in this case the test script got to run a couple of extra loops
while waiting for LinuxCNC (Task & Motion) to respond to the earlier
single-step requests, and thus queued up a bunch of extra single-step
requests, which restarted the G-code program being single-stepped.

The G-code program starts out by resetting the counter, so when the
test finished it saw the new counter from the (incorrect) next run of
the G-code program.

This commit changes the test program to avoid this race, by waiting for
each step to start and complete before considering issuing another step.

Author: SebKuzminsky

tests/single-step/test-ui.py

@@ -44,7 +44,7 @@ def print_state():
 c.home(2)
 l.wait_for_home([1, 1, 1, 0, 0, 0, 0, 0, 0])
 c.mode(linuxcnc.MODE_AUTO)
-        
+
 
 #
 # run the .ngc test file, starting from the special line
@@ -56,28 +56,63 @@ def print_state():
 def mod_5_is_0(x):
     return abs((x+epsilon) % 5) < 2*epsilon
 
-# Take first step
+
+def wait_complete_step():
+
+    '''The normal `linuxcnc.command.wait_complete()` function does not
+    understand single-stepping.  It waits for the `state` to return to
+    `RCS_DONE` but this does not happen when single-stepping, `state`
+    stays at `RCS_EXEC` while waiting for the next step.
+
+    This function instead waits for status.task.execState to tell us
+    that Task is no longer waiting for Motion in any way.'''
+
+    timeout = 5.0
+    start = time.time()
+
+    # Wait for the command to be acknowledged by Task (FIXME or is it motion?).
+    while time.time() - start < timeout:
+        s.poll()
+        if s.echo_serial_number >= c.serial:
+            break
+        time.sleep(0.1)
+
+    # Wait for Task to be done waiting for Motion.
+    while time.time() - start < timeout:
+        s.poll()
+        if s.exec_state not in [ linuxcnc.EXEC_WAITING_FOR_MOTION, linuxcnc.EXEC_WAITING_FOR_MOTION_AND_IO, linuxcnc.EXEC_WAITING_FOR_MOTION_QUEUE ]:
+            return
+        time.sleep(0.1)
+
+    raise SystemExit('timeout in wait_complete_step()')
+
+
+# Take first three steps (these cause no motion).
+c.auto(linuxcnc.AUTO_STEP)
+c.auto(linuxcnc.AUTO_STEP)
 c.auto(linuxcnc.AUTO_STEP)
+wait_complete_step()
 
 count = 0
 while True:
     s.poll()
+    if s.interp_state == linuxcnc.INTERP_IDLE:
+        sys.stderr.write("Finished:  Detected program finish\n")
+        break
+
     (x, y) = (h["Xpos"], h["Ypos"])
     if mod_5_is_0(x) and mod_5_is_0(y):
-        # Both axes on goal; make next step and let motion start
+        # Both axes on goal; command the next step and wait for it to finish.
         sys.stderr.write("Taking step from X%.2f Y%.2f\n" % (x, y))
         c.auto(linuxcnc.AUTO_STEP)
-        time.sleep(0.1)
+        wait_complete_step()
 
     print_state()
 
     count += 1
     if count >= 1000:  # Shouldn't happen, but prevent runaways
         sys.stderr.write("Finished:  Exceeded max cycles\n")
         sys.exit(1)
-    if s.interp_state == linuxcnc.INTERP_IDLE:
-        sys.stderr.write("Finished:  Detected program finish\n")
-        break
 
     time.sleep(0.1)