Gmoccapy - Odd behaviour in G96 (CSS) mode

[andypugh]

LinuxCNC 2.9.4

Open Gmoccapy, home and go to MDI mode

G96 S100
M3

The HAL pin spindle.0.speed-out and the Gmoccapy display briefly show the correct speed, then go to 100.

M3 (again)

Now the HAL pin works properly, but the Gmoccapy speed display has many too many digits.

[andypugh]

(Tested with Axis GUI, and the HAL pin part of the problem is not seen)

[Sigma1912]

[edit]
Removed my comments about the the 'infinite' acceleration values. These are not related to the described issue.

[Sigma1912]

There seems to be something generally wrong with the python status channel when 'G96' is active (Note the 'speed' entry):

This after 'M4' command:

[edit]
Changed the first image to show behavior is not affected by X positional value

[Sigma1912]

Seems the display issue is caused by gmoccapy using the 'speed' value from the python status channel to display the spindle speed.

In 'constant surface speed' mode (ie G96) the spindle speed value in the python status channel reflects the max css-speed set by the optional 'D'-word OR the default value '1e30'.

Not sure yet what is causing the issue with the motion halpin 'spindle.n.speed-out' not working correctly.

[andypugh]

The HAL pin works fine if you issue a second M3 command. It smells like some sort of special-handling in Gmoccapy, possibly aimed at working around the Python interface problem.

[Sigma1912]

Yes, it also works if I add self.linuxcnc.mdi('g4 p0.1') after self.linuxcnc.mdi(cmd):

Note that 'm3' or 'g4 p0.05' instead of 'g4 p0.1' does NOT work so I'm wondering if this is a timing issue.

I'm trying to compare debug output from AXIS vs Gmoccapy but so far I have not found a good debug setting.

[Sigma1912]

Ok so I get this in Gmoccapy when the pin is not working:

usrmotReadEmcmotStatus: Split read timeout
Issuing EMC_TASK_PLAN_EXECUTE -- 	 (  +509,+280,   +19,g96\032s100\032m3,)
emcTaskPlanLevel() returned 0
NML_INTERP_LIST(0x55add86430e0)::append(nml_msg_ptr{size=56,type=EMC_SPINDLE_SPEED}) : list_size=1, line_number=0
NML_INTERP_LIST(0x55add86430e0)::append(nml_msg_ptr{size=56,type=EMC_SPINDLE_SPEED}) : list_size=2, line_number=0
emcTaskPlanExecute(g96 s100 m3) returned 0
emcTaskPlanLevel() returned 0
NML_INTERP_LIST(0x55add86430e0)::get(): {size=56, type=EMC_SPINDLE_SPEED}, list_size=1
emcTaskPlanLevel() returned 0
Issuing EMC_SPINDLE_SPEED -- 	 ( +1316,+56,    +0,    +0,    +0,0.000000,0.000000,0.000000,)
NML_INTERP_LIST(0x55add86430e0)::get(): {size=64, type=EMC_SPINDLE_ON}, list_size=0
emcTaskPlanLevel() returned 0
Issuing EMC_SPINDLE_ON -- 	 ( +1304,+64,    +0,    +0,    +0,1000000000000000019884624838656.000000,15915.494309,0.000000,    +1,)
mdi_execute_hook: MDI command 'g96 s100 m3' done (remaining: 0)
Issuing EMC_SPINDLE_ON -- 	 ( +1304,+64,   +20,    +0,    +0,100.000000,0.000000,0.000000,    +0,)

and this is with AXIS:

Issuing EMC_TASK_SET_MODE -- 	 (  +504,+24,   +18,    +3,)
NML_INTERP_LIST(0x559b467d60e0)::clear(): discarding 0 items
NML_INTERP_LIST(0x559b467d60e0)::append(nml_msg_ptr{size=24,type=EMC_TASK_PLAN_SYNCH}) : list_size=1, line_number=0
emcTaskPlanSynch() returned 0
NML_INTERP_LIST(0x559b467d60e0)::get(): {size=24, type=EMC_TASK_PLAN_SYNCH}, list_size=0
emcTaskPlanLevel() returned 0
task: main loop took 0.024550 seconds
Issuing EMC_TASK_PLAN_SYNCH -- 	 (  +516,+24,    +0,)
emcTaskPlanSynch() returned 0
Issuing EMC_TASK_PLAN_EXECUTE -- 	 (  +509,+280,   +19,g96\032s100\032m3,)
emcTaskPlanLevel() returned 0
NML_INTERP_LIST(0x559b467d60e0)::append(nml_msg_ptr{size=56,type=EMC_SPINDLE_SPEED}) : list_size=1, line_number=0
NML_INTERP_LIST(0x559b467d60e0)::append(nml_msg_ptr{size=56,type=EMC_SPINDLE_SPEED}) : list_size=2, line_number=0
emcTaskPlanExecute(g96 s100 m3) returned 0
emcTaskPlanLevel() returned 0
NML_INTERP_LIST(0x559b467d60e0)::get(): {size=56, type=EMC_SPINDLE_SPEED}, list_size=1
emcTaskPlanLevel() returned 0
Issuing EMC_SPINDLE_SPEED -- 	 ( +1316,+56,    +0,    +0,    +0,0.000000,0.000000,47.945040,)
NML_INTERP_LIST(0x559b467d60e0)::get(): {size=64, type=EMC_SPINDLE_ON}, list_size=0
emcTaskPlanLevel() returned 0
Issuing EMC_SPINDLE_ON -- 	 ( +1304,+64,    +0,    +0,    +0,1000000000000000019884624838656.000000,15915.494309,47.945040,    +1,)
mdi_execute_hook: MDI command 'g96 s100 m3' done (remaining: 0)

For some reason there is an extra line at the end when Gmoccapy executes the same command ('g96 s100 m3'):

Issuing EMC_SPINDLE_ON -- 	 ( +1304,+64,   +20,    +0,    +0,100.000000,0.000000,0.000000,    +0,)

[Sigma1912]

I think I might have found the responsible code section in gmoccapy.py but I have run out of time for today.

[Sigma1912]

I've been wondering as to why the '_set_spindle()' would run when an MDI command was executed and got a bit farther with this by adding some debug print statements like this:

To test I start the config, home the axes change to MDI and issue 'g96 d33333 s100 m3' (the 'd' word is to prevent the GUI window from expanding horizontally due to the 1e30 bug described above):

NML_INTERP_LIST(0x58d92a177160)::append(nml_msg_ptr{size=56,type=EMC_SPINDLE_SPEED}) : list_size=1, line_number=0
NML_INTERP_LIST(0x58d92a177160)::append(nml_msg_ptr{size=56,type=EMC_SPINDLE_SPEED}) : list_size=2, line_number=0
NML_INTERP_LIST(0x58d92a177160)::get(): {size=56, type=EMC_SPINDLE_SPEED}, list_size=1
NML_INTERP_LIST(0x58d92a177160)::get(): {size=64, type=EMC_SPINDLE_ON}, list_size=0
running: on_rbt_stop_clicked
running: on_rbt_forward_clicked
running: _set_spindle
forward, resetting to:  100.0

Note the last three debug prints confirming that the '_set_spindle()' function has indeed run and thus the 'spindle.0.speed-out' pin has been set to 'self.stat.settings[2]' which is '100' .

Then I issue another 'g96 d33333 s100 m3':

NML_INTERP_LIST(0x58d92a177160)::append(nml_msg_ptr{size=56,type=EMC_SPINDLE_SPEED}) : list_size=1, line_number=0
NML_INTERP_LIST(0x58d92a177160)::append(nml_msg_ptr{size=56,type=EMC_SPINDLE_SPEED}) : list_size=2, line_number=0
NML_INTERP_LIST(0x58d92a177160)::get(): {size=56, type=EMC_SPINDLE_SPEED}, list_size=1
NML_INTERP_LIST(0x58d92a177160)::get(): {size=64, type=EMC_SPINDLE_ON}, list_size=0

This time the '_set_spindle()' function is not executed and the 'spindle.0.speed-out' pin is now set correctly.

So the next question is: Why are those functions called at all?

[Sigma1912]

This would indicate that those functions are called by the GUI (glade):

So the issue seems to be that these 'clicked' handlers are called when those GUI buttons change state when 'm3' is called the first time.

And indeed if we change the MDI command sequence from

g96 d33333 s100 m3
m3

to

g96 d33333 s100 m3
m4

The 'spindle.0.speed-out' pin is now set incorrectly to '-100' because we have a change in the GUI button states and the 'clicked' handler functions are called.

[Sigma1912]

Seems that 'set_active(True)' triggers the glade 'clicked' event.

which I guess is required as it is used to change the widget image.

I believe the core of this is that this condition in '_set_spindle()' has stopped working due to a race condition:

By the time this is executed the interpreter is already IDLE which is why I could make it work by adding 'g4 p0.1' to the mdi command.

Note that we have had issues like this in Gmoccapy before:
#3120
#3129

The difference with this current problem here is that we cannot fix this by artificially prolonging the mdi command without breaking blending of stacked mdi commands.

[Sigma1912]

To fix the GUI speed display issue I can only think of using the actual hal pin value instead of the unreliable status channel:

To fix the issue with 'spindle.0.speed-out' being wrong I moved the existing handler functions for 'rbt_forward' and 'rbt_reverse' to the 'released' signal and created two new handler functions that do not call 'self._set_spindle()' function for the 'clicked' event:

This seems to fix the two issues in my tests.

[andypugh]

A bit late now, but to answer one of your earlier questions, the git "blame" view can be useful to try to guess why something was done. eg:
https://github.com/LinuxCNC/linuxcnc/blame/2.9/src/emc/usr_intf/gmoccapy/gmoccapy.py#L4050