[etherlab-users] Problem with distributed clocks in RTAI: "Slave did not sync after 5000 ms" & "No Sync Error"

[Mohsen Alizadeh Noghani]

Update: I increased EC_DC_SYNC_WAIT_MS to 50000 (50 seconds). I also set
debug level to 1, "ethercat debug 1" and the closest slave 0 (reference
clocks) gets to syncing is after about 48 seconds! ("abs_sync_diff" =
approximately 1.156 ms).
At this point, the value starts to diverge and ends at 1.77 seconds at the
50 seconds mark.
*kernel: [14573.717225] EtherCAT DEBUG 0-0: Sync after 47800 ms:    1156111
ns*
.
.
.

*kernel: [14575.919495] EtherCAT DEBUG 0-0: Sync after 49996 ms: 1771539607
ns*

*kernel: [14575.923534] EtherCAT WARNING 0-0: Slave did not sync after
50012 ms.*

*kernel: [14575.923536] EtherCAT DEBUG 0-0:
app_start_time=593344410354840000*

*kernel: [14575.923538] EtherCAT DEBUG 0-0:
 app_time=593344420279840000*

*kernel: [14575.923539] EtherCAT DEBUG 0-0:
 start_time=593344420379840000*

*kernel: [14575.923540] EtherCAT DEBUG 0-0:     cycle_time=500000*

*kernel: [14575.923542] EtherCAT DEBUG 0-0:     shift_time=125000*

*kernel: [14575.923543] EtherCAT DEBUG 0-0:      remainder=0*

*kernel: [14575.923544] EtherCAT DEBUG 0-0:
start=593344420380465000*

*kernel: [14575.923545] EtherCAT DEBUG 0-0: Setting DC cyclic operation
start time to 593344420380465000.*

*kernel: [14575.928611] EtherCAT DEBUG 0-0: Setting DC AssignActivate to
0x0300.*

*kernel: [14575.941292] EtherCAT 0: Domain 0: Working counter changed to
3/6.*

*kernel: [14576.000500] EtherCAT DEBUG 0-0: Processing register request...*

*kernel: [14576.004685] EtherCAT DEBUG 0-0: Register request successful.*
*kernel: [14576.050335] EtherCAT DEBUG 0-0: Now in SAFEOP.*

- Is there something wrong with the algorithm used for nudging
"abs_sync_diff" towards 0?
- If so, why does it work perfectly fine in the userspace, but not in RTAI?

Best,
Mohsen

On Fri, Oct 19, 2018 at 1:05 PM Mohsen Alizadeh Noghani <
m.alizad3h at gmail.com> wrote:

> Hello everyone.
> I'm using kernel 3.4.6, RTAI 4.0 and IgH Master 1.5.2.
> When running a simple RTAI program
> <https://github.com/mohse-n/L7N_EtherLab/blob/master/rtai/rtai_sample.c>
> that uses distributed clocks (basically the dc_rtai example), I encounter
> the following kernel log:
>
> *kernel: [ 1891.643677] EtherCAT 0: Link state of ecm0 changed to UP.*
> *kernel: [ 1891.647798] EtherCAT 0: 2 slave(s) responding on main device.*
> *kernel: [ 1891.647800] EtherCAT 0: Slave states on main device: PREOP.*
> *kernel: [ 1891.647837] EtherCAT 0: Scanning bus.*
> *kernel: [ 1892.083268] EtherCAT 0: Bus scanning completed in 436 ms.*
> *kernel: [ 1892.083271] EtherCAT 0: Using slave 0 as DC reference clock.*
> *kernel: [ 1906.700138] EtherCAT: Requesting master 0...*
> *kernel: [ 1906.700142] EtherCAT: Successfully requested master 0.*
> *kernel: [ 1906.700160] EtherCAT 0: Domain0: Logical address 0x00000000,
> 24 byte, expected working counter 6.*
> *kernel: [ 1906.700161] EtherCAT 0:   Datagram domain0-0-main: Logical
> offset 0x00000000, 24 byte, type LRW.*
> *kernel: [ 1906.700185] EtherCAT 0: Master thread exited.*
> *kernel: [ 1906.700187] EtherCAT 0: Starting EtherCAT-OP thread.*
> *kernel: [ 1906.704215] ec_rtai_sample: RT timer started with 3116/3117
> ticks.*
> *kernel: [ 1906.704218] ec_rtai_sample: Initialized.*
> *kernel: [ 1911.935059] EtherCAT WARNING 0-0: Slave did not sync after
> 5000 ms.*
> *kernel: [ 1911.946039] EtherCAT 0: Domain 0: Working counter changed to
> 3/6.*
> *kernel: [ 1914.070216] EtherCAT ERROR 0-0: Failed to set OP state, slave
> refused state change (SAFEOP + ERROR).*
> *kernel: [ 1914.073870] EtherCAT ERROR 0-0: AL status message 0x002D: "No
> Sync Error".*
> *kernel: [ 1914.081189] EtherCAT 0-0: Acknowledged state SAFEOP.*
> *kernel: [ 1919.308375] EtherCAT WARNING 0-1: Slave did not sync after
> 5000 ms.*
> *kernel: [ 1919.321187] EtherCAT 0: Domain 0: Working counter changed to
> 6/6.*
> *kernel: [ 1921.449013] EtherCAT ERROR 0-1: Failed to set OP state, slave
> refused state change (SAFEOP + ERROR).*
> *kernel: [ 1921.452670] EtherCAT ERROR 0-1: AL status message 0x002D: "No
> Sync Error".*
> *kernel: [ 1921.459991] EtherCAT 0-1: Acknowledged state SAFEOP.*
> *kernel: [ 1921.469158] EtherCAT 0: Slave states on main device: SAFEOP.*
>
> The slaves (servo drives) would give an alarm related to EtherCAT
> communication.
> Apparently, the slaves are unable to sync after 5 seconds. But why?
> (Note: I have tested the distributed clocks example in userspace and it
> works, so I don't think the issue is from the slaves' side.)
> Best,
> Mohsen
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.etherlab.org/pipermail/etherlab-users/attachments/20181020/455d15d7/attachment-0003.htm>