/tests/abort/g64/test.ini is not working well.

[zz912]

Branche 2.9 RIP Installation

I experimented with warning Python WaitCommandComplete timed out
https://forum.linuxcnc.org/38-general-linuxcnc-questions/52141-warning-python-waitcommandcomplete-timed-out

I found out that /tests/abort/g64/test.ini is not working well.

If you run it normally, the result is OK.

zdenek@cnc:~/linuxcnc/linuxcnc-2.9-WAIT_COMPLETE/src$ ../scripts/linuxcnc -r ../tests/abort/g64/test.ini
Machine configuration file is 'test.ini'
Starting LinuxCNC...
emc/iotask/ioControl.cc 786: can't load tool table.
linuxcnc TPMOD=tpmod HOMEMOD=homemod EMCMOT=motmod
Note: Using POSIX non-realtimezdenek@cnc:~/linuxcnc/linuxcnc-2.9-WAIT_COMPLETE/src$ ../scripts/linuxcnc -r ../tests/abort/g64/test.ini
Machine configuration file is 'test.ini'
Starting LinuxCNC...
emc/iotask/ioControl.cc 786: can't load tool table.
linuxcnc TPMOD=tpmod HOMEMOD=homemod EMCMOT=motmod
Note: Using POSIX non-realtime
Found file(LIB): /home/zdenek/linuxcnc/linuxcnc-2.9-WAIT_COMPLETE/lib/hallib/core_sim.hal
Found file(REL): ./motion-test.hal
task: main loop took 0.120195 seconds
task: main loop took 0.061635 seconds
task: main loop took 0.019434 seconds
Running command 'G61'
G61 post-command:  Control mode = 610; tolerances = P0.001 Q0.000
Running program 'test.ngc'
task: main loop took 0.020032 seconds
Error - Python WaitCommandComplete timed out 
G61 pre-abort:  Control mode = 610; tolerances = P0.000 Q0.000
task: main loop took 0.035752 seconds
G61 post-abort:  Control mode = 610; tolerances = P0.000 Q2.000
z=0.0; max_x = 5.000000; max_y = 1.000000; samples = 6245

task: main loop took 0.019740 seconds
G61 redo post-command:  Control mode = 610; tolerances = P0.000 Q2.000
Running program 'test.ngc'
task: main loop took 0.021903 seconds
Error - Python WaitCommandComplete timed out 
G61 redo pre-abort:  Control mode = 610; tolerances = P0.000 Q2.000
task: main loop took 0.035966 seconds
G61 redo post-abort:  Control mode = 610; tolerances = P0.000 Q2.000
z=0.5; max_x = 5.000000; max_y = 1.000000; samples = 5650

task: main loop took 0.019586 seconds
Running command 'G61.1'
G61.1 post-command:  Control mode = 611; tolerances = P0.000 Q2.000
Running program 'test.ngc'
task: main loop took 0.021529 seconds
Error - Python WaitCommandComplete timed out 
G61.1 pre-abort:  Control mode = 611; tolerances = P0.000 Q2.000
G61.1 post-abort:  Control mode = 611; tolerances = P0.000 Q2.000
z=1.0; max_x = 4.999999; max_y = 1.000000; samples = 5700

G61.1 redo post-command:  Control mode = 611; tolerances = P0.000 Q2.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G61.1 redo pre-abort:  Control mode = 611; tolerances = P0.000 Q2.000
G61.1 redo post-abort:  Control mode = 611; tolerances = P0.000 Q2.000
z=1.5; max_x = 4.999999; max_y = 1.000000; samples = 5648

Running command 'G64P0.5Q0'
G64P0.5 post-command:  Control mode = 640; tolerances = P0.500 Q0.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64P0.5 pre-abort:  Control mode = 640; tolerances = P0.500 Q0.000
G64P0.5 post-abort:  Control mode = 640; tolerances = P0.500 Q0.000
z=2.0; max_x = 4.499999; max_y = 0.999878; samples = 5572

G64P0.5 redo post-command:  Control mode = 640; tolerances = P0.500 Q0.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64P0.5 redo pre-abort:  Control mode = 640; tolerances = P0.500 Q0.000
G64P0.5 redo post-abort:  Control mode = 640; tolerances = P0.500 Q0.000
z=2.5; max_x = 4.499999; max_y = 0.999878; samples = 5588

Running command 'G64'
G64 post-command:  Control mode = 640; tolerances = P0.000 Q0.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64 pre-abort:  Control mode = 640; tolerances = P0.000 Q0.000
G64 post-abort:  Control mode = 640; tolerances = P0.000 Q0.000
z=3.0; max_x = 3.725244; max_y = 0.999686; samples = 5743

G64 redo post-command:  Control mode = 640; tolerances = P0.000 Q0.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64 redo pre-abort:  Control mode = 640; tolerances = P0.000 Q0.000
G64 redo post-abort:  Control mode = 640; tolerances = P0.000 Q0.000
z=3.5; max_x = 3.725244; max_y = 0.999686; samples = 5697

Running command 'G64Q6'
G64P0Q6 post-command:  Control mode = 640; tolerances = P0.000 Q6.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64P0Q6 pre-abort:  Control mode = 640; tolerances = P0.000 Q6.000
G64P0Q6 post-abort:  Control mode = 640; tolerances = P0.000 Q6.000
z=4.0; max_x = 0.000001; max_y = 0.000001; samples = 5439

G64P0Q6 redo post-command:  Control mode = 640; tolerances = P0.000 Q6.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64P0Q6 redo pre-abort:  Control mode = 640; tolerances = P0.000 Q6.000
G64P0Q6 redo post-abort:  Control mode = 640; tolerances = P0.000 Q6.000
z=4.5; max_x = 0.000000; max_y = 0.000000; samples = 5470

Exiting with 0 errors
Shutting down and cleaning up LinuxCNC...
task: 64183 cycles, min=0.000007, max=0.061635, avg=0.001142, 32 latency excursions (> 10x expected cycle time of 0.001000s)
link (updating variable file): Adresář nebo soubor neexistuje
Note: Using POSIX non-realtime
Found file(LIB): /home/zdenek/linuxcnc/linuxcnc-2.9-WAIT_COMPLETE/lib/hallib/core_sim.hal
Found file(REL): ./motion-test.hal
task: main loop took 0.120195 seconds
task: main loop took 0.061635 seconds
task: main loop took 0.019434 seconds
Running command 'G61'
G61 post-command:  Control mode = 610; tolerances = P0.001 Q0.000
Running program 'test.ngc'
task: main loop took 0.020032 seconds
Error - Python WaitCommandComplete timed out 
G61 pre-abort:  Control mode = 610; tolerances = P0.000 Q0.000
task: main loop took 0.035752 seconds
G61 post-abort:  Control mode = 610; tolerances = P0.000 Q2.000
z=0.0; max_x = 5.000000; max_y = 1.000000; samples = 6245

task: main loop took 0.019740 seconds
G61 redo post-command:  Control mode = 610; tolerances = P0.000 Q2.000
Running program 'test.ngc'
task: main loop took 0.021903 seconds
Error - Python WaitCommandComplete timed out 
G61 redo pre-abort:  Control mode = 610; tolerances = P0.000 Q2.000
task: main loop took 0.035966 seconds
G61 redo post-abort:  Control mode = 610; tolerances = P0.000 Q2.000
z=0.5; max_x = 5.000000; max_y = 1.000000; samples = 5650

task: main loop took 0.019586 seconds
Running command 'G61.1'
G61.1 post-command:  Control mode = 611; tolerances = P0.000 Q2.000
Running program 'test.ngc'
task: main loop took 0.021529 seconds
Error - Python WaitCommandComplete timed out 
G61.1 pre-abort:  Control mode = 611; tolerances = P0.000 Q2.000
G61.1 post-abort:  Control mode = 611; tolerances = P0.000 Q2.000
z=1.0; max_x = 4.999999; max_y = 1.000000; samples = 5700

G61.1 redo post-command:  Control mode = 611; tolerances = P0.000 Q2.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G61.1 redo pre-abort:  Control mode = 611; tolerances = P0.000 Q2.000
G61.1 redo post-abort:  Control mode = 611; tolerances = P0.000 Q2.000
z=1.5; max_x = 4.999999; max_y = 1.000000; samples = 5648

Running command 'G64P0.5Q0'
G64P0.5 post-command:  Control mode = 640; tolerances = P0.500 Q0.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64P0.5 pre-abort:  Control mode = 640; tolerances = P0.500 Q0.000
G64P0.5 post-abort:  Control mode = 640; tolerances = P0.500 Q0.000
z=2.0; max_x = 4.499999; max_y = 0.999878; samples = 5572

G64P0.5 redo post-command:  Control mode = 640; tolerances = P0.500 Q0.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64P0.5 redo pre-abort:  Control mode = 640; tolerances = P0.500 Q0.000
G64P0.5 redo post-abort:  Control mode = 640; tolerances = P0.500 Q0.000
z=2.5; max_x = 4.499999; max_y = 0.999878; samples = 5588

Running command 'G64'
G64 post-command:  Control mode = 640; tolerances = P0.000 Q0.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64 pre-abort:  Control mode = 640; tolerances = P0.000 Q0.000
G64 post-abort:  Control mode = 640; tolerances = P0.000 Q0.000
z=3.0; max_x = 3.725244; max_y = 0.999686; samples = 5743

G64 redo post-command:  Control mode = 640; tolerances = P0.000 Q0.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64 redo pre-abort:  Control mode = 640; tolerances = P0.000 Q0.000
G64 redo post-abort:  Control mode = 640; tolerances = P0.000 Q0.000
z=3.5; max_x = 3.725244; max_y = 0.999686; samples = 5697

Running command 'G64Q6'
G64P0Q6 post-command:  Control mode = 640; tolerances = P0.000 Q6.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64P0Q6 pre-abort:  Control mode = 640; tolerances = P0.000 Q6.000
G64P0Q6 post-abort:  Control mode = 640; tolerances = P0.000 Q6.000
z=4.0; max_x = 0.000001; max_y = 0.000001; samples = 5439

G64P0Q6 redo post-command:  Control mode = 640; tolerances = P0.000 Q6.000
Running program 'test.ngc'
Error - Python WaitCommandComplete timed out 
G64P0Q6 redo pre-abort:  Control mode = 640; tolerances = P0.000 Q6.000
G64P0Q6 redo post-abort:  Control mode = 640; tolerances = P0.000 Q6.000
z=4.5; max_x = 0.000000; max_y = 0.000000; samples = 5470

Exiting with 0 errors
Shutting down and cleaning up LinuxCNC...
task: 64183 cycles, min=0.000007, max=0.061635, avg=0.001142, 32 latency excursions (> 10x expected cycle time of 0.001000s)
link (updating variable file): Adresář nebo soubor neexistuje
Note: Using POSIX non-realtime

(Error - Python WaitCommandComplete timed out - this is my warnings)

If you change this line

linuxcnc/tests/abort/g64/test-ui.py

Line 96 in bc56a86

c.wait_complete()

to c.wait_complete(600)
and let the test run in its entirety. The result is not OK.

zdenek@cnc:~/linuxcnc/linuxcnc-2.9-WAIT_COMPLETE/src$ ../scripts/linuxcnc -r ../tests/abort/g64/test.ini
Machine configuration file is 'test.ini'
Starting LinuxCNC...
emc/iotask/ioControl.cc 786: can't load tool table.
linuxcnc TPMOD=tpmod HOMEMOD=homemod EMCMOT=motmod
Note: Using POSIX non-realtime
Found file(LIB): /home/zdenek/linuxcnc/linuxcnc-2.9-WAIT_COMPLETE/lib/hallib/core_sim.hal
Found file(REL): ./motion-test.hal
task: main loop took 0.124241 seconds
task: main loop took 0.062023 seconds
task: main loop took 0.019336 seconds
Running command 'G61'
G61 post-command:  Control mode = 610; tolerances = P0.001 Q0.000
Running program 'test.ngc'
task: main loop took 0.020136 seconds
G61 pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR control mode 640 != expected 610
task: main loop took 0.035286 seconds
G61 post-abort:  Control mode = 610; tolerances = P0.000 Q2.000
z=0.0; max_x = 5.000000; max_y = 1.000000; samples = 259203

task: main loop took 0.021404 seconds
G61 redo post-command:  Control mode = 610; tolerances = P0.000 Q2.000
Running program 'test.ngc'
task: main loop took 0.022898 seconds
G61 redo pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR control mode 640 != expected 610
task: main loop took 0.035590 seconds
G61 redo post-abort:  Control mode = 610; tolerances = P0.000 Q2.000
z=0.5; max_x = 5.000000; max_y = 1.000000; samples = 259133

task: main loop took 0.022062 seconds
Running command 'G61.1'
G61.1 post-command:  Control mode = 611; tolerances = P0.000 Q2.000
Running program 'test.ngc'
task: main loop took 0.022341 seconds
G61.1 pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR control mode 640 != expected 611
G61.1 post-abort:  Control mode = 611; tolerances = P0.000 Q2.000
z=1.0; max_x = 4.999999; max_y = 1.000000; samples = 259333

G61.1 redo post-command:  Control mode = 611; tolerances = P0.000 Q2.000
Running program 'test.ngc'
G61.1 redo pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR control mode 640 != expected 611
G61.1 redo post-abort:  Control mode = 611; tolerances = P0.000 Q2.000
z=1.5; max_x = 4.999999; max_y = 1.000000; samples = 259805

Running command 'G64P0.5Q0'
G64P0.5 post-command:  Control mode = 640; tolerances = P0.500 Q0.000
Running program 'test.ngc'
G64P0.5 pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR blend tolerance P1.000 != expected P0.500
*** ERROR naive CAM tolerance Q2.000 != expected Q0.000
G64P0.5 post-abort:  Control mode = 640; tolerances = P0.500 Q0.000
z=2.0; max_x = 4.499999; max_y = 0.999878; samples = 201457

G64P0.5 redo post-command:  Control mode = 640; tolerances = P0.500 Q0.000
Running program 'test.ngc'
G64P0.5 redo pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR blend tolerance P1.000 != expected P0.500
*** ERROR naive CAM tolerance Q2.000 != expected Q0.000
G64P0.5 redo post-abort:  Control mode = 640; tolerances = P0.500 Q0.000
z=2.5; max_x = 4.499999; max_y = 0.999878; samples = 201877

Running command 'G64'
G64 post-command:  Control mode = 640; tolerances = P0.000 Q0.000
Running program 'test.ngc'
G64 pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR blend tolerance P1.000 != expected P0.000
*** ERROR naive CAM tolerance Q2.000 != expected Q0.000
G64 post-abort:  Control mode = 640; tolerances = P0.000 Q0.000
z=3.0; max_x = 3.725244; max_y = 0.999686; samples = 198436

G64 redo post-command:  Control mode = 640; tolerances = P0.000 Q0.000
Running program 'test.ngc'
G64 redo pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR blend tolerance P1.000 != expected P0.000
*** ERROR naive CAM tolerance Q2.000 != expected Q0.000
G64 redo post-abort:  Control mode = 640; tolerances = P0.000 Q0.000
z=3.5; max_x = 3.725244; max_y = 0.999686; samples = 198694

Running command 'G64Q6'
G64P0Q6 post-command:  Control mode = 640; tolerances = P0.000 Q6.000
Running program 'test.ngc'
G64P0Q6 pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR blend tolerance P1.000 != expected P0.000
*** ERROR naive CAM tolerance Q2.000 != expected Q6.000
G64P0Q6 post-abort:  Control mode = 640; tolerances = P0.000 Q6.000
z=4.0; max_x = 0.000000; max_y = 0.000000; samples = 247463

G64P0Q6 redo post-command:  Control mode = 640; tolerances = P0.000 Q6.000
Running program 'test.ngc'
G64P0Q6 redo pre-abort:  Control mode = 640; tolerances = P1.000 Q2.000
*** ERROR blend tolerance P1.000 != expected P0.000
*** ERROR naive CAM tolerance Q2.000 != expected Q6.000
G64P0Q6 redo post-abort:  Control mode = 640; tolerances = P0.000 Q6.000
z=4.5; max_x = 0.000000; max_y = 0.000000; samples = 247853

Exiting with 16 errors
Shutting down and cleaning up LinuxCNC...
task: 2123346 cycles, min=0.000007, max=0.062023, avg=0.001115, 35 latency excursions (> 10x expected cycle time of 0.001000s)
link (updating variable file): Adresář nebo soubor neexistuje
Note: Using POSIX non-realtime
LinuxCNC terminated with an error.  You can find more information in the log:
    /home/zdenek/linuxcnc_debug.txt
and
    /home/zdenek/linuxcnc_print.txt
as well as in the output of the shell command 'dmesg' and in the terminal

This Issue points to two problems:

1. Python WaitCommandComplete timed out has no Warning
2. /tests/abort/g64/test.ini returns Errors

[andypugh]

Is the problem here that the default wait.complete() waits 5 seconds, then times-out with no error, whereas wait.complete(600) wait for 10 minutes, and so the whole test times out with a fail?

[zz912]

Yes.

[zz912]

I would like to ask the author of this test @zultron to take a look at it.