[etherlab-dev] Bus scan takes long time at low rates

Tue Apr 30 12:01:14 CEST 2013

Hi Steffen,

what host-OS do you use? I tried the same with Linux-VM (with RT-Preempt
kernel) and Windows-host, got the same result. You may try following:
* Use a RT-Preempt kernel in the VM
* Use ethercat-capable network-drivers in the VM (e1000 or maybe e1000e
should work with Oracle VM Virtualbox)
* Use a Linux Host with RT-Preempt kernel and set the VM to realtime
priority (98)
I've never tried this before, but this might reduce issues.

Regards
Jürgen

Am 30.04.2013 10:22, schrieb Steffen Dalgard:
> Hi,
> I am setting up a environment for development an test.
> In order to make it easy to replicate at different sites it is running
> in a virtual machine inside Oracle VM VirtualBox Manager.
> The EtherCAT slaves are connected to a dedicated bridged interface
> using the generic Ethernet driver.
> As you understand this is not a high performance system.
>  
> Before activating the master it takes below 1 sec for scanning the bus
> with 5 slaves.
> When starting the userspace application and activating the master for
> cyclic operation the rescan take very long time. It seems that the
> rescan gets slower when cycle time are long. In my application I am
> using 10HZ cycle time.
> In the attached logs the time for scanning is about 3 minutes.
> During the rescan period the processor load increase significantly (*
> 20) but the packets on the bus stays constant at 10 packets pr. sec.
>  
> Anyone having experience how to reduce time for scanning?
>  
> I can reduce the cycle time downto 100HZ but the scan time is still long.
> A downside is that I get more timeout / unmatched packets.
>  
> Anyone having ideas what causing packet loss?
>  
> The virtual machine is running
> Linux 10.04 LTS
> gcc (Ubuntu 4.4.3-4ubuntu5.1) 4.4.3 is used for compilation
> I have attached three logs showing syslog output
>  
> More details and examples can be added if needed.
>
> Any comments welcome.
>
> Best regards
> Steffen Dalgard
> SINTEF ICT
> Norway
>  
>  
> "SYSLOG messages when starting up Master"
> Apr 30 09:29:09 ecmaster-vm kernel: [86526.177110] EtherCAT: Master
> driver 1.5.1 41dc9a4a0f76
> Apr 30 09:29:09 ecmaster-vm kernel: [86526.178626] EtherCAT: 1 master
> waiting for devices.
> Apr 30 09:29:09 ecmaster-vm kernel: [86526.184362] ec_generic:
> EtherCAT master generic Ethernet device module 1.5.1 41dc9a4a0f76
> Apr 30 09:29:09 ecmaster-vm kernel: [86526.184375] EtherCAT: Accepting
> 08:00:27:BF:57:AC as main device for master 0.
> Apr 30 09:29:09 ecmaster-vm kernel: [86526.184391] EtherCAT 0:
> Starting EtherCAT-IDLE thread.
> Apr 30 09:29:09 ecmaster-vm kernel: [86526.184423] EtherCAT 0: Link
> state of ecm0 changed to UP.
> Apr 30 09:29:09 ecmaster-vm kernel: [86526.188311] EtherCAT 0: 5
> slave(s) responding on main device.
> Apr 30 09:29:09 ecmaster-vm kernel: [86526.188315] EtherCAT 0: Slave
> states on main device: PREOP.
> Apr 30 09:29:09 ecmaster-vm kernel: [86526.193124] EtherCAT 0:
> Scanning bus.
> Apr 30 09:29:10 ecmaster-vm kernel: [86526.774874] EtherCAT 0: Bus
> scanning completed in 580 ms.
> Apr 30 09:29:10 ecmaster-vm kernel: [86526.774879] EtherCAT 0: Using
> slave 0 as DC reference clock.
> Apr 30 09:31:20 ecmaster-vm kernel: [86656.548051] EtherCAT WARNING 0:
> 1 datagram TIMED OUT!
> Apr 30 09:35:17 ecmaster-vm kernel: [86894.412791] EtherCAT WARNING 0:
> 1 datagram TIMED OUT!
> Apr 30 09:35:17 ecmaster-vm kernel: [86894.412811] EtherCAT WARNING 0:
> 1 datagram UNMATCHED!
> Apr 30 09:36:04 ecmaster-vm kernel: [86940.780824] EtherCAT WARNING 0:
> 2 datagrams TIMED OUT!
> Apr 30 09:36:04 ecmaster-vm kernel: [86940.780842] EtherCAT WARNING 0:
> 2 datagrams UNMATCHED!
>  
> "SYSLOG messages when starting application"
> Apr 30 09:38:49 ecmaster-vm kernel: [87106.284019] EtherCAT:
> Requesting master 0...
> Apr 30 09:38:49 ecmaster-vm kernel: [87106.284231] EtherCAT:
> Successfully requested master 0.
> Apr 30 09:38:49 ecmaster-vm kernel: [87106.284279] EtherCAT 0:
> Domain0: Logical address 0x00000000, 2 byte, expected working counter 3.
> Apr 30 09:38:49 ecmaster-vm kernel: [87106.284284] EtherCAT 0:  
> Datagram domain0-0-main: Logical offset 0x00000000, 2 byte, type LRW.
> Apr 30 09:38:49 ecmaster-vm kernel: [87106.284287] EtherCAT 0:
> Domain1: Logical address 0x00000002, 0 byte, expected working counter 0.
> Apr 30 09:38:49 ecmaster-vm kernel: [87106.284668] EtherCAT 0: Master
> thread exited.
> Apr 30 09:38:49 ecmaster-vm kernel: [87106.284671] EtherCAT 0:
> Starting EtherCAT-OP thread.
> Apr 30 09:38:49 ecmaster-vm kernel: [87106.285073] EtherCAT WARNING 0:
> 1 datagram UNMATCHED!
> Apr 30 09:38:56 ecmaster-vm kernel: [87113.384968] EtherCAT 0: Domain
> 0: Working counter changed to 2/3 (2+0).
> Apr 30 09:38:59 ecmaster-vm kernel: [87116.386563] EtherCAT 0: Domain
> 0: Working counter changed to 3/3 (3+0).
> Apr 30 09:39:00 ecmaster-vm kernel: [87117.288055] EtherCAT 0: Slave
> states on main device: PREOP, OP.
>  
>  
> "SYSLOG messages when forcing bus rescan by extracting and inserting
> one of the slaves"
> Apr 30 09:41:25 ecmaster-vm kernel: [87261.585150] EtherCAT 0: Domain
> 0: Working counter changed to 2/3 (2+0).
> Apr 30 09:41:25 ecmaster-vm kernel: [87261.585644] EtherCAT 0: 4
> slave(s) responding on main device.
> Apr 30 09:41:25 ecmaster-vm kernel: [87262.085167] EtherCAT 0:
> Scanning bus.
> Apr 30 09:44:02 ecmaster-vm kernel: [87418.885938] EtherCAT 0: Bus
> scanning completed in 157196 ms.
> Apr 30 09:44:02 ecmaster-vm kernel: [87418.885953] EtherCAT 0: Using
> slave 0 as DC reference clock.
> Apr 30 09:44:04 ecmaster-vm kernel: [87420.685695] EtherCAT 0: 5
> slave(s) responding on main device.
> Apr 30 09:44:04 ecmaster-vm kernel: [87420.685710] EtherCAT 0: Slave
> states on main device: INIT, PREOP, OP.
> Apr 30 09:44:04 ecmaster-vm kernel: [87421.185114] EtherCAT 0:
> Scanning bus.
> Apr 30 09:47:25 ecmaster-vm kernel: [87621.985808] EtherCAT 0: Bus
> scanning completed in 201196 ms.
> Apr 30 09:47:25 ecmaster-vm kernel: [87621.985825] EtherCAT 0: Using
> slave 0 as DC reference clock.
> Apr 30 09:47:30 ecmaster-vm kernel: [87627.184968] EtherCAT 0: Domain
> 0: Working counter changed to 3/3 (3+0).
> Apr 30 09:47:31 ecmaster-vm kernel: [87628.088202] EtherCAT 0: Slave
> states on main device: PREOP, OP.
>
>  
>
>
> _______________________________________________
> etherlab-dev mailing list
> etherlab-dev at etherlab.org
> http://lists.etherlab.org/mailman/listinfo/etherlab-dev

-- 
Dipl.-Inform. Jürgen Kunz

Technische Universität Darmstadt <http://www.tu-darmstadt.de>
FG Simulation, Systemoptimierung und Robotik
<http://www.sim.tu-darmstadt.de>
Hochschulstr. 10
64289 Darmstadt

Tel.: ++49 (0) 6151-16-70383
Fax: ++49 (0) 6151-16-6648
E-Mail: kunz(at)sim.tu-darmstadt.de
Homepage: http://www.sim.tu-darmstadt.de
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.etherlab.org/pipermail/etherlab-dev/attachments/20130430/b9f6571c/attachment-0004.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: kunz.vcf
Type: text/x-vcard
Size: 464 bytes
Desc: not available
URL: <http://lists.etherlab.org/pipermail/etherlab-dev/attachments/20130430/b9f6571c/attachment-0005.vcf>