Waiting for S.Axes problem

Hello,

I have problems running the example files that uses Axis as display. Some examples if i change to Touchy it works but i want to use Axis in this case.
I downloaded the linuxcnc source and added a little bit of debug. By the way, there is NO "NML_FILE = emc.nml" in the INI file.
¿ What should i do ?

Thanks you in advance,
VNR

vnr@VnrCNC:~/linuxcnc-dev/src$ linuxcnc
LINUXCNC - 2.6.0~pre
Machine configuration directory is '/home/vnr/linuxcnc/configs/univstep'
Machine configuration file is 'univstep.ini'
Starting LinuxCNC...
io started
halcmd loadusr io started
task pid=27237
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
USRMOT: ERROR: command timeout
axis.py waiting for s.axes
USRMOT: ERROR: command timeout
axis.py waiting for s.axes
USRMOT: ERROR: command timeout
USRMOT: ERROR: command timeout
USRMOT: ERROR: command timeout
axis.py (waiting for s.axes raise error): A configuration error is preventing LinuxCNC from starting.
More information may be available when running from a terminal.
Shutting down and cleaning up LinuxCNC...
/usr/bin/milltask (pid 27237) died on signal 11, backtrace stored in /tmp/backtrace.27237
/usr/bin/milltask exiting
/usr/bin/linuxcnc: line 388: 27237 Segmentation fault $EMCTASK -ini "$INIFILE"
Cleanup done
LinuxCNC terminated with an error. You can find more information in the log:
/home/vnr/linuxcnc_debug.txt
and
/home/vnr/linuxcnc_print.txt
as well as in the output of the shell command 'dmesg' and in the terminal

/home/vnr/linuxcnc_debug.txt:
Can not find -sec MOT -var MOT -num 1
Can not find -sec IO -var IO -num 1
Can not find -sec LINUXCNC -var NML_FILE -num 1
Can not find -sec EMC -var NML_FILE -num 1
27184
PID TTY STAT TIME COMMAND
27237
PID TTY STAT TIME COMMAND
27237 pts/0 S+ 0:00 milltask -ini /home/vnr/linuxcnc/configs/univstep/univstep.ini
PID TTY STAT TIME COMMAND
27237 pts/0 T+ 0:00 milltask -ini /home/vnr/linuxcnc/configs/univstep/univstep.ini
PID TTY STAT TIME COMMAND
27237 pts/0 T+ 0:00 milltask -ini /home/vnr/linuxcnc/configs/univstep/univstep.ini
PID TTY STAT TIME COMMAND
Stopping realtime threads
Unloading hal components

/home/vnr/linuxcnc_print.txt:
RUN_IN_PLACE=no
LINUXCNC_DIR=
LINUXCNC_BIN_DIR=/usr/bin
LINUXCNC_TCL_DIR=/usr/lib/tcltk/linuxcnc
LINUXCNC_SCRIPT_DIR=
LINUXCNC_RTLIB_DIR=/usr/realtime-2.6.32-122-rtai/modules/linuxcnc
LINUXCNC_CONFIG_DIR=
LINUXCNC_LANG_DIR=/usr/share/linuxcnc/tcl/msgs
INIVAR=inivar
HALCMD=halcmd
LINUXCNC_EMCSH=/usr/bin/wish8.5
INIFILE=/home/vnr/linuxcnc/configs/univstep/univstep.ini
PARAMETER_FILE=univstep.var
TASK=milltask
HALUI=
DISPLAY=axis
Starting LinuxCNC server program: linuxcncsvr
Loading Real Time OS, RTAPI, and HAL_LIB modules
Starting LinuxCNC IO program: io
Starting TASK program: milltask
Starting DISPLAY program: axis
Killing task linuxcncsvr, PID=27184
Killing task milltask, PID=27237
Removing HAL_LIB, RTAPI, and Real Time OS modules
Removing NML shared memory segments

Can you run Sim > Axis > Axis simulator from the configuration selector?

Sim -> Axis -> axis OK
Sim -> Axis -> axis_mm OK
Sim -> Axis -> axis_lathe OK
Sim -> axis-iocontrolv2-demo OK
Sim -> axis_noio OK

Sim->py Same kind of error.

I had to change some lines in INI file:
[PYTHON]
PLUGIN_DIR=/usr/share/doc/linuxcnc/examples/sample-configs/sim/pysubs
#/home/mah/emc2-tc/configs/sim/pysubs

Also i had to comment some lines in core_sim_test.hal, because HAL didnt get some iocontrol pins. I dont know if this is a cause or a symptom of the problem
# estop loopback
#net estop-loop iocontrol.0.user-enable-out iocontrol.0.emc-enable-in
# create signals for tool loading loopback
#net tool-prep-loop iocontrol.0.tool-prepare iocontrol.0.tool-prepared
#net tool-change-loop iocontrol.0.tool-change iocontrol.0.tool-changed

RESULT:

Print file information:
RUN_IN_PLACE=no
LINUXCNC_DIR=
LINUXCNC_BIN_DIR=/usr/bin
LINUXCNC_TCL_DIR=/usr/lib/tcltk/linuxcnc
LINUXCNC_SCRIPT_DIR=
LINUXCNC_RTLIB_DIR=/usr/realtime-2.6.32-122-rtai/modules/linuxcnc
LINUXCNC_CONFIG_DIR=
LINUXCNC_LANG_DIR=/usr/share/linuxcnc/tcl/msgs
INIVAR=inivar
HALCMD=halcmd
LINUXCNC_EMCSH=/usr/bin/wish8.5
LINUXCNC - 2.6.0~pre
Machine configuration directory is '/usr/share/doc/linuxcnc/examples/sample-configs/sim'
Machine configuration file is 'py.ini'
INIFILE=/usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PARAMETER_FILE=sim_mm.var
TASK=milltask
HALUI=halui
DISPLAY=axis
Starting LinuxCNC...
Starting LinuxCNC server program: linuxcncsvr
Loading Real Time OS, RTAPI, and HAL_LIB modules
Starting LinuxCNC IO program: io
io started
libnml/cms/cms_cfg.cc 495: No buffer-line entry found for buffer toolCmd in config file no-iotask.nml.
libnml/nml/nml.cc 368: NML: cms_config returned -1.

**********************************************************
* Current Directory = /usr/share/doc/linuxcnc/examples/sample-configs/sim
*
**********************************************************
* BufferName = toolCmd
* ProcessName = tool
* Config File = no-iotask.nml
* error_type = 0 (NML_NO_ERROR)
************************************************************

libnml/cms/cms_cfg.cc 495: No buffer-line entry found for buffer toolSts in config file no-iotask.nml.
libnml/nml/nml.cc 368: NML: cms_config returned -1.

**********************************************************
* BufferName = toolSts
* ProcessName = tool
* Config File = no-iotask.nml
* error_type = 0 (NML_NO_ERROR)
************************************************************

libnml/cms/cms_cfg.cc 501: No process-line entry found for process tool connecting to buffer emcError in config file no-iotask.nml and no applicable defaults were found.

**********************************************************
* BufferName = emcError
* ProcessName = tool
* Config File = no-iotask.nml
* error_type = 3 (NML_INVALID_CONFIGURATION)
************************************************************

halcmd loadusr io started
Starting HAL User Interface program: halui
Starting TASK program: milltask
task pid=3386
Starting DISPLAY program: axis
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
axis.py waiting for s.axes
Shutting down and cleaning up LinuxCNC...
Killing task linuxcncsvr, PID=3351
Killing task milltask, PID=3386
Timeout, trying kill -9
Removing HAL_LIB, RTAPI, and Real Time OS modules
Removing NML shared memory segments
Cleanup done

Debug file information:
Can not find -sec MOT -var MOT -num 1
Can not find -sec IO -var IO -num 1
Can not find -sec EMCIO -var EMCIO -num 1
Can not find -sec LINUXCNC -var NML_FILE -num 1
Can not find -sec DISPLAY -var INTRO_GRAPHIC -num 1
emcToolCmd buffer not available
toolSts buffer not available
emcError buffer not available
can't connect to NML buffers in no-iotask.nml
<commandline>:0: io exited without becoming ready
axis.py (waiting for s.axes raise error): A configuration error is preventing LinuxCNC from starting.
More information may be available when running from a terminal.
3351
PID TTY STAT TIME COMMAND
3386
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
PID TTY STAT TIME COMMAND
3386 ? S 0:00 milltask -ini /usr/share/doc/linuxcnc/examples/sample-configs/sim/py.ini
/usr/bin/linuxcnc: line 388: 3386 Killed $EMCTASK -ini "$INIFILE"
PID TTY STAT TIME COMMAND
Stopping realtime threads
Unloading hal components

Kernel message information:
[ 336.891037] I-pipe: Domain RTAI registered.
[ 336.891043] RTAI[hal]: <3.8.1> mounted over IPIPE-NOTHREADS 2.6-03.
[ 336.891045] RTAI[hal]: compiled with gcc version 4.4.3 (Ubuntu 4.4.3-4ubuntu5) .
[ 336.891048] RTAI[hal]: mounted (IPIPE-NOTHREADS, IMMEDIATE (INTERNAL IRQs DISPATCHED), ISOL_CPUS_MASK: 0).
[ 336.891050] PIPELINE layers:
[ 336.891052] f9e61e20 9ac15d93 RTAI 200
[ 336.891054] c085cb20 0 Linux 100
[ 336.905846] RTAI[malloc]: global heap size = 2097152 bytes, <BSD>.
[ 336.905906] RTAI[sched]: IMMEDIATE, MP, USER/KERNEL SPACE: <with RTAI OWN KTASKs>, kstacks pool size = 524288 bytes.
[ 336.905909] RTAI[sched]: hard timer type/freq = APIC/12557035(Hz); default timing: periodic; linear timed lists.
[ 336.905912] RTAI[sched]: Linux timer freq = 250 (Hz), TimeBase freq = 2712802000 hz.
[ 336.905914] RTAI[sched]: timer setup = 999 ns, resched latency = 2944 ns.
[ 336.905963] RTAI[usi]: enabled.
[ 336.942370] RTAI[math]: loaded.
[ 344.752590] RTAI[math]: unloaded.
[ 344.779379] SCHED releases registered named ALIEN RTGLBH
[ 344.792382] RTAI[malloc]: unloaded.
[ 344.892006] RTAI[sched]: unloaded (forced hard/soft/hard transitions: traps 0, syscalls 0).
[ 344.893737] I-pipe: Domain RTAI unregistered.
[ 344.893742] RTAI[hal]: unmounted.

latency test: max jitter (ns) servo= near 12500, base= near 15500
i tested some ACPI changes in the bios but nothing happened
i will add a little bit of debug information into the source code and recompile again

Finally i found the bug:
The Axis prints "waiting for s.axes" because hal_ppmc driver crashes at line 1147.

src/hal/drivers/hal_ppmc.c -> funcion static void read_encoders(slot_data_t *slot)
1146 } else {
1147 *(slot->encoder.vel) = vel; // encoder without timestamp
1148 }

The tracking history:
1) Axis prints "waiting for s.axes" because src/emc/ini/iniaxis.cc fails in function loadAxis at emcAxisSetBacklash
2) src/emc/task/taskintf.cc fails at function emcAxisSetBacklash because function usrmotWriteWriteEmcmotCommand fails.
3) src/emc/motion/usrmotintf.cc fails at function usrmotWriteEmcmotCommand because function usrmotReadEmcmotStatus always return s.commandNumEcho = 0 (must be equal to commandNum sent)
4) Fixed this Axis loads.
5) But now i get an RTAPI fault.
6) So i read rtfaults.txt ( git.linuxcnc.org/gitweb?p=linuxcnc.git;a...rtfaults.txt;hb=HEAD ) and found that the problem was hal_ppmc.c at line 1147.
7) I commented that line and recompile.
8) I got back with the change in 4) and recompile again.
9) Now i can run the univstep example config (with Axis and hal_ppmc driver). I can get out of estop, home all and MDI G0 X100 Y100 Z100.

VNR wrote:

Finally i found the bug:
The Axis prints "waiting for s.axes" because hal_ppmc driver crashes at line 1147.

src/hal/drivers/hal_ppmc.c -> funcion static void read_encoders(slot_data_t *slot)
1146 } else {
1147 *(slot->encoder.vel) = vel; // encoder without timestamp
1148 }

The tracking history:
1) Axis prints "waiting for s.axes" because src/emc/ini/iniaxis.cc fails in function loadAxis at emcAxisSetBacklash
2) src/emc/task/taskintf.cc fails at function emcAxisSetBacklash because function usrmotWriteWriteEmcmotCommand fails.
3) src/emc/motion/usrmotintf.cc fails at function usrmotWriteEmcmotCommand because function usrmotReadEmcmotStatus always return s.commandNumEcho = 0 (must be equal to commandNum sent)
4) Fixed this Axis loads.
5) But now i get an RTAPI fault.
6) So i read rtfaults.txt ( git.linuxcnc.org/gitweb?p=linuxcnc.git;a...rtfaults.txt;hb=HEAD ) and found that the problem was hal_ppmc.c at line 1147.
7) I commented that line and recompile.
8) I got back with the change in 4) and recompile again.
9) Now i can run the univstep example config (with Axis and hal_ppmc driver). I can get out of estop, home all and MDI G0 X100 Y100 Z100.

WOW, I can't believe this is the first person to hit this bug! Now, this code has been only in the
development version of LinuxCNC for a long time, waiting for the long-fabled 2.5 version to come
out. This was done in November 2010!

OHHHHH! NOW I understand! This error REQUIRES the board to be very old (Pre ver 2),
from before late 2006.

What is going on is that the function export_encoders() should always export the velocity pin,
no matter what rev the board is. But, only if the board is greater than ver 2 does the current code
do that. For some reason, this was bundled with the encoder timestamp and index-enable
features. Older USC boards don't have properly working encoder index logic.
But, all encoders should be able to produce a scaled velocity from the position delta, so it
should always export the velocity HAL pin.

I am driving to the CNC Workshop on Wednesday, and will be coming back on Sunday.
I'm a little afraid to hack into this and make things worse.
But, if VNR doesn't need the
scaled velocity, commenting out that line is fine. If he does want that, then the fix is to
move lines 2141-2145 up before line 2132. Since no USC board has timestamping of
the encoder counter, it will just scale the encoder delta value.

I'm not sure I can cobble together a board of that old revision, that used a 5 V FPGA
instead of the newer 3.3/1.8 V FPGA, so I can't just put old firmware in a new board
for testing.

Well, thanks to VNR for finding a bug I should have tracked down!

Jon

jmelson wrote:

I'm a little afraid to hack into this and make things worse.

Well, after looking at it a bit, the fix seemed so obvious and simple, that
I went ahead and pushed, seems to be in the v2.5_branch tree, is
this the right place to be putting this?

Thanks,

Jon