Delay on sending Ethernet (UDP) packets

[kaflick]

Hello,
  We are starting another EIP project with the 52259 and are to the point where we are running the system with a robot controller that also commands our system through EIP (Ethernet Industrial Protocol).  Everything works correctly except the sends of our half of the communications are delayed.  I am logging when we receive an incoming communication and when we send an outgoing communication (there is a sequence number in EIP which makes this easy).

At the beginning of the communication stream the numbers of incoming communications and outgoing communications are logged together and appear together on the ethernet (using wireshark).  As the communications continue our outgoing communications fall farther and farther behind.  After a while our communications stop.  At this point we have logged receiving and sending communications together but wireshark reports our output messages are around 1000 messages behind the incoming messages.  In other words we have received message 10000 and sent message 10000 but the messages wireshark has seen are incoming message 10000 and outgoing message 9000 which were adjacent on the wire.  These numbers do seem to be about correct, we fall behind at just about a 1 per 10 rate.

No errors are reported by any of the calls to uTasker in sending these messages and I have added extra buffers to see if it made a difference (it did not).

The Ethernet does not seem to be too busy to allow sending at the correct rate (they are only 32 bytes long and sent every 50 ms) and this is the same rate as our old system (on the 52235) so we have a faster processor with twice as much memory but the Ethernet can't seem to keep up.

Any suggestions?

Thanks for your attention
Keith Flick

[mark]

Hi Keith

What is the delay between the correct incoming fame number and the correct outgoing frame number (as seen by wireshark)?

If there are 1000 frames delayed it would be 5s (at 50ms rate).

Since the Ethernet has a limited number of buffers (say I couldn't image more that 8 frames delay before they are sent out on to the line, assuming that there was no reception delay (I understood that you have confirmed that this is the case).

Can they be being delay in a switch (store and forward)? I don't see how the M52259 differs from the M52235 in respect to the EMAC (?)

Regards

Mark

P.S: What is your Ethernet/IP solution like in terms of performance and features? There is an increasing demand for Ethernet/IP and thus some potential (!)

[kaflick]

I have changed some timer values (to change the communication rate)  to see what that did (not much).

Previously I had a 10 mb Ethernet Hub with three system plugged in, our controller(uTasker), the robot controller (Windows Vista) and the computer I was running wireshark on (XP).

I had anywhere from 10 to 60 seconds of delay between synchronous reads and writes (on the uTasker system) on that system.

I had changed it to eliminate the hub and the XP computer so I could test it with 100mb direct connection between the robot controller system and the uTasker system (I don't have a 100mb switch).  This arrangement gave me 13,875 reads and writes on the uTasker side, all nicely synchronous (no missing packets or any variation in spacing).  The last two packets wireshark (now running on the robot controller system) read were robot controller packet 13,875 and uTasker packet 13,140.  Looking back to the robot controller packet 13,140 gives about 42 seconds of delay.

Looking ate these 735 packets (at 32 bytes per packet) gives about 23k of space which is close to the free space on our system, there isn't any way they are being stored in stack space or heap waiting to be written?

Is there anything that I should be setting up in the Ethernet config that may effect priorities or timing?

Still looking.

Keith Flick

[kaflick]

In regards to the EIP software we are using a package from Real Time Automation.  It was horribly expensive (IMHO) but it was purchased before I was involved and they didn't ask my opinion :-).  I do believe that it was just about the only choice when they purchased it (around 2004 I believe) for a different project.  That project didn't go anywhere so when the previous one that I worked on started they said "Here use this.".  They could have had some better documentation but I think they assumed that anyone who used it would be EIP gurus (which I certainly wasn't.).  I believe that the current packages from RTA are much more reasonable in price but I was only told this is passing and wasn't given any details.  We did manage to get it to work under uTasker but it was obviously aimed at a PC implementation on a system with infinite memory compared to our systems.  In fact I was told by another user that it was impossible to get it and an OS to run on a system with 32k of ram :-).  It is nice having our HUGE 64K of ram now.

I am hoping to work with the free packages available on Sourceforge or from the ODVA website but I have not been able to yet.  I have not found anyone who has used them on an actual project yet.

Keith Flick

[mark]

Keith

The EIP stack that you are using may be queueing messages waiting for transmission. The Ethernet driver doesn't do any queueing - it just sends from one of the limited Ethernet buffer (if there was any queueing here it would be at maximum the number of buffers). I do still wonder why the M5223x project behaves differently to the M52259 project.

Thanks for the EIP stack details. I do know of another uTasker based project using a commerical stack with the same memory restrictions. I believe that it essentially runs OK with 2ms polling rate.

Regards

Mark

[kaflick]

It's not queuing in the EIP stack, I made sure of that by logging the send after the return from fnSendUDP.  I'm not getting any errors, it's logging the receives and the sends together but there is up to a 40 second delay on the wire.  It starts out in sync and falls farther and farther behind.

Do you have any suggestions on anything else to try?

Keith Flick

[mark]

Keith

Can you try to get a log of the time that the EIP stack 'sends' the UDP frame and the time that the Ethernet content is 'really' sent.

If there is a SW delay involved it woudl be measurable here - although I would expect that the EIP USD transmission directly calls the UDP transmission routine that in turn fills the Ethernet output buffer. The Ethernet output buffer will be sent as soon as the Ethernet controller can send it (usually practically immediately). Even of there was a problem with the Ethernet buffers (eg. Ethernet tramsmitter not synchronouse to the user's buffer) it would, in the worst case, lead to a delay of the maximum number of buffers reserved for Ethernet Tx use. (Such a 'theoretical' loss of synchronisation would also correct itself as soon as the controller can send all buffers freely (I would expect)). If you have (for example) 10 Tx buffers reserved and there is a frame being sent every 50ms I still couldn't imaging a delay of more than 500ms.

Have you tried possitioning a hub directly connected to the transmitter so that Wireshark can see this directly? (Just to exclude that the delay is in a switch somewhere?).

Regards

Mark

[kaflick]

I was using a dumb hub at 10mb (no smarts at all, just the wires connected together electronically).

At 100mb I was directly connected with the robot controller connected to our system without any hub or switch with wireshark running on the robot controller.

In neither case was there anything external that could be slowing down our transmissions.

The time difference at the end of the one sequence was the 40 seconds I mentioned previously, the system logged receiving packet 13,875 and sending packet 13,875 at the same time.  Wireshark saw Robot controller packet 13,875 and uTasker packet 13,140 at the same time and robot controller packet 13,140 42 seconds previously (at the same time as uTasker packet 12442, robot controller 12442 was from 35 seconds earlier).  All of the packets were logged synchronously, from 1 through 13,875 so the uTasker system should have sent them at the same time.

[mark]

Hi Keith

I would put some debug code in the lowest level Ethernet transmit routine. Since you know where the counter is in the data you could display the value as the frame is submitted to the Ethernet controller (extern QUEUE_TRANSFER fnStartEthTx(QUEUE_TRANSFER DataLen, unsigned char *ptr_put)).
If you have some free ports you could set the value in binary (or at least a nibbel or two of it) to these ports to get a real-time trace of the frame counter being sent.

At the moment I can only explain such a delay as being an internal queue in the software since the delays are so long. If you can verify that these frame numbers are really 'off' at this location it would prove it. If the counters match then it woudl mean that the Ethernet controller was delaying transmission of up to 25k of data in the transmit queue - this I still can't imagine since I don't think that such a large amount of memory will be allocated to the buffers (?). I don't think that the external PHY can be queuing anything (??)

Regards

Mark

[kaflick]

I'll do that and let you know what I find.

[kaflick]

O.K.  It looks just like the previous description.  QUEUE_TRANSFER fnStartEthTx(QUEUE_TRANSFER DataLen, unsigned char *ptr_put)) is being called where you would expect it to be called.  In the EIP routine that sends the UDP message it calls fnSendUDP which calls fnSendIP which call fnWrite one or more times and finally calls fnWrite(Ethernet_handle, 0, 0) which ends up calling fnStartEthTx before it returns up through fnSendUDP which returns a positive integer which is >0.  The sequence number is correct in the buffer.  I ran it with both systems being reset which caused the sequence number to be the same and then I only reset the uTasker system which caused them to be offset by 9291 just to make sure I wasn't displaying the wrong sequence number.  It looks like the correct data is being written to the hardware at the correct time.  I have a request in to Freescale to see what they have to say.