AN00120_100Mbit_ethernet_demo crashes

Technical questions regarding the XTC tools and programming with XMOS.
Post Reply
Sternmull
New User
Posts: 3
Joined: Fri Dec 30, 2016 9:45 am

AN00120_100Mbit_ethernet_demo crashes

Post by Sternmull »

I use the latest lib_ethernet (master at 88afc60f21fb59b1f5d79d36179fe303a573a71d, all other dependencies are coming from todays master branches as well) with the XL216 Slicekit. The demo works as advertised until i spend a bit of time at the end of "case rx.packet_ready()" in icmp.xc and send it many packets.

All I did was adding the following lines before the break in "case rx.packet_ready()":

Code: Select all

      {
          timer tmr;
          unsigned t;
          tmr :> t;
          tmr when timerafter(t + XS1_TIMER_MHZ * 200) :> void;
      }
Everything looks good when i run the application (console tells about incoming ARP packets, device responds to ping). Now I send UDP packets at maximum speed with the following Python 3 script:

Code: Select all

import socket
if __name__ == '__main__':
    with socket.socket(type=socket.SOCK_DGRAM) as s:
        s.connect(('192.168.1.178', 1234))
        msg = bytes(1460)
        while True:
            s.send(msg)


This immediately crashes the application with the following output in the console:
xrun: Program received signal ET_LOAD_STORE, Memory access exception.
[Switching to tile[1] core[1]]
mii_lite_free_in_buffer (this=@0x7f9b0, base0=<value optimized out>) at F:/xmos/git/lib_ethernet/lib_ethernet/src/mii_lite_driver.xc:321

321 set(base-4, -get(base-4));
If I run it with the debugger it stops at the following stacktrace:
9 get() mii_lite_driver.xc:136 0x00041214
8 mii_lite_free_in_buffer() mii_lite_driver.xc:321 0x00041214
7 _i.mii_if._Smii_handler_0.3.release_packet() mii.xc:49 0x0004071e
6 mii_ethernet_aux() mii_ethernet_mac.xc:281 0x00040bfc
5 _Smii_ethernet_mac_0.task.mii_ethernet_aux.3() <synthesized>:344 0x0004108c
4 __start_other_cores() 0x00041e44
3 mii_ethernet_mac() mii_ethernet_mac.xc:341 0x000409da
2 __main__main_tile_1_task_mii_ethernet_mac_0() main.xc:93 0x000404ce
1 __start_core() 0x0004200c
When I remove my lines from "case rx.packet_ready()" then there is no crash.

It looks like the buffer management is unable to handle situations where packets come in faster than they get processed by the application. This is very unfortunate because I want to use the ethernet connection at its maximum speed while doing some processing on the incoming packets. And I can not guarantee that all packets will be processed faster than they come in. I would prefer dropped packets instead of a crash.


srinie
XCore Addict
Posts: 158
Joined: Thu Mar 20, 2014 8:04 am

Post by srinie »

Hi Sternmull,
Just a note if that could be of any use:

While the Ethernet component would 've been tested for line rate, there could be a suspicion on the data rate that the device receives. Is it possible to check the IFG of the packets from the host once?
A delay at the host sends in the while(1) working good?

regards,
Srinivas
srinie
XCore Addict
Posts: 158
Joined: Thu Mar 20, 2014 8:04 am

Post by srinie »

Hi,
The demo filters ARP and ICMP packets and hence there won't be any rx.packet_ready() events for UDP packets to this core!

Btw, where exactly the below code is added, inside the same case()?
Sternmull wrote:{
timer tmr;
unsigned t;
tmr :> t;
tmr when timerafter(t + XS1_TIMER_MHZ * 200) :> void;
}
regards,
/srinie
Sternmull
New User
Posts: 3
Joined: Fri Dec 30, 2016 9:45 am

Post by Sternmull »

Hello srinie,

to avoid any confusion i have uploaded my changes to github: https://github.com/sternmull/lib_ethern ... its/master

About the filtering: The application does see the UDP packets. The comment in the original example says it filters ARP and IP packets. This would include UDP packets. Counting incoming packets also confirms that UDP packets are passed to the application.

I added a few lines to trace the incoming bandwidth once per second. When I remove the "sleep" from the "case rx.packet_read()" then it shows around 93Mbit/s and runs without problems. When I add the sleep it takes at most a few seconds until I see the crash. This even happens when i modify the Python script to send only 3Mbit/s.

I struggle to understand your first post. Not sure what is ment with "line rate" and no clue about IFG. When I change the python script to sleep 1ms after each sent packet it seems to run without problems. But that is at around 10kBit/s with a 1ms sleep for each sent packet while there is a 200us sleep per received packet in the xmos application. So there is oviously no stress on the xmos side.
srinie
XCore Addict
Posts: 158
Joined: Thu Mar 20, 2014 8:04 am

Post by srinie »

Ah, I see. It gets ARP/IP packets.
Sternmull wrote: Not sure what is meant with "line rate" and no clue about IFG. When
If its a 100 mbps version, I meant this as line rate; with IFG being the inter-frame gap as per the spec, but host python script may not ve control on this parameter.

Sternmull wrote:When I remove the "sleep" from the "case rx.packet_read()" then it shows around 93Mbit/s and runs without problems.
200 us processing looks well to be available in this core, am not able to figure out the cause for the crash.

I wish to try this example on my hardware once, but few things I would start if I wish to check the processing available in the same core:
(i) time the rx.packet_ready() event; and also to check the elapse time of the case block;
(ii) move the timer event as a separate case (as you did for reporting), add a delay in it to ascertain how much the core can withstand for any application logic


Thanks,
/srinie
Sternmull
New User
Posts: 3
Joined: Fri Dec 30, 2016 9:45 am

Post by Sternmull »

You are right, low level properties like the inter frame gap are controlled by the switches between my PC and the XMOS-Device. Python has no chance to mess this up. I am pretty sure we can rule out such problems because it runs without problems at 93Mbit/s (which is pretty much the theoretical maximum) when I remove the delay in the xmos application.

I suspect the buffer management of lib_ethernet to fail when the packets are not fetched fast enough. With the library versions that are installed by the xTimeComposer when I create AN00120_100Mbit_ethernet_demo from the Examples it just hangs (mii_lite_interrupt.S no longer jumps to buffers_available, mii_lite_data_t.next_buffer stays at -1). When I use the github versions it crashes. In both cases it looks like it stumbles because the available buffers are used up.
maxwinkel
Member
Posts: 9
Joined: Wed May 03, 2017 8:40 am

Post by maxwinkel »

Hi all!

I don't know, if its still relevant:
I can confirm the problem, as I had the same. The crash basically is a null pointer exception happening when the user application does not pick up the received packets. The intermediate MII task does pick up all the packets, but keeps the first packet in the buffer (because it's not yet delivered to the user application). Therefore this particular slot in the ringbuffer keeps occupied, which then leads to several problems.

I've fixed it this way which works fine for me:

Code: Select all

diff --git a/src/trunk/lib_ethernet/src/mii_ethernet_mac.xc b/src/trunk/lib_ethernet/src/mii_ethernet_mac.xc
index d5b06ff..60750d1 100644
--- a/src/trunk/lib_ethernet/src/mii_ethernet_mac.xc
+++ b/src/trunk/lib_ethernet/src/mii_ethernet_mac.xc
@@ -126,6 +126,9 @@ static void mii_ethernet_aux(client mii_if i_mii,
       case i_rx[int i].get_packet(ethernet_packet_info_t &desc,
                                    char data[n],
                                    unsigned n):
+
+//        debug_printf("i_rx[].get_packet(): incoming_data = %x\n", incoming_data);
+
         if (client_state[i].status_update_state == STATUS_UPDATE_PENDING) {
           data[0] = link_status;
           data[1] = link_speed;
@@ -272,7 +275,7 @@ static void mii_ethernet_aux(client mii_if i_mii,
           update_client_state(client_state, i_rx, n_rx);
         }
         break;
-      case mii_incoming_packet(mii_info):
+      case incoming_data == NULL => mii_incoming_packet(mii_info):
         int * unsafe data;
         int nbytes;
         unsigned timestamp;
@@ -280,6 +283,7 @@ static void mii_ethernet_aux(client mii_if i_mii,
 
         if (incoming_data) {
           // Can only handle one packet at a time at this level
+//          debug_printf("mii_incoming_packet: incoming_data != 0 (= %x) -> release packet\n", incoming_data);
           i_mii.release_packet(data);
           break;
         }
@@ -315,6 +319,7 @@ static void mii_ethernet_aux(client mii_if i_mii,
             }
           }
           if (incoming_tcount == 0) {
+//            debug_printf("mii_incoming_packet: incoming_tcount = 0 -> release packet\n", incoming_data);
             i_mii.release_packet(incoming_data);
             incoming_data = null;
           }
diff --git a/src/trunk/lib_ethernet/src/mii_lite_driver.xc b/src/trunk/lib_ethernet/src/mii_lite_driver.xc
index 284ee19..0df759f 100644
--- a/src/trunk/lib_ethernet/src/mii_lite_driver.xc
+++ b/src/trunk/lib_ethernet/src/mii_lite_driver.xc
@@ -8,6 +8,9 @@
 #include "print.h"
 #include "mii_buffering.h"
 
+#define DEBUG_UNIT LIB_ETHERNET
+#include "debug_print.h"
+
 // TODO: implement mii_driver straight in mii_lld.
 void mii_lite_driver(in buffered port:32 p_rxd,
                      in port p_rxdv,
@@ -142,6 +145,8 @@ static int get(int addr) {
 void mii_lite_buffer_init(struct mii_lite_data_t &this,
                           chanend c_in, chanend c_notifications,
                           chanend c_out, int buffer[], int number_words) {
+//  debug_printf("mii_lite_buffer_init()\n");
+
   int address;
   this.notify_seen = 1;
   this.notify_last = 1;
@@ -174,6 +179,10 @@ void mii_notify(struct mii_lite_data_t &this, chanend c_notifications) {
     this.notify_last = !this.notify_last;
     outuchar(c_notifications, this.notify_last);
   }
+//  else
+//  {
+//      debug_printf("mii_notify: notify_last != notify_seen -> Skipping notification!\n");
+//  }
 }
 
 select mii_notified(struct mii_lite_data_t &this, chanend c_notifications) {
@@ -185,6 +194,9 @@ case inuchar_byref(c_notifications, this.notify_seen):
 {char * unsafe, unsigned, unsigned} mii_lite_get_in_buffer(struct mii_lite_data_t &this,
                                                            chanend c_notifications) {
   unsafe {
+
+//      debug_printf("mii_lite_get_in_buffer(): read_bank_rd_ptr = %d, read_bank_wr_ptr = %d\n", this.read_bank_rd_ptr, this.read_bank_wr_ptr);
+
     if (this.read_bank_rd_ptr != this.read_bank_wr_ptr) {
       unsigned bank = (this.read_bank >> this.read_bank_rd_ptr) & 0x1;
       unsigned n_bytes = get(this.read_ptr[bank]);
@@ -205,7 +217,10 @@ case inuchar_byref(c_notifications, this.notify_seen):
         }
 
         if (this.read_bank_rd_ptr != this.read_bank_wr_ptr)
+        {
+//            debug_printf("mii_lite_get_in_buffer(): rd_ptr != wr_ptr -> More packets -> Sending another notification.\n");
           mii_notify(this, c_notifications);
+        }
 
         unsigned time_stamp = get(ret_val);
 
@@ -214,6 +229,7 @@ case inuchar_byref(c_notifications, this.notify_seen):
 
       }
     }
+//    debug_printf("mii_lite_get_in_buffer(): Returning NULL\n");
     return {(char * unsafe) 0, 0, 0};
   }
 }
@@ -221,6 +237,8 @@ case inuchar_byref(c_notifications, this.notify_seen):
 #pragma unsafe arrays
 static void mii_commit_buffer(struct mii_lite_data_t &this, unsigned int current_buffer,
                             unsigned int length, chanend c_notifications) {
+//  debug_printf("mii_commit_buffer(%x) [bank = %d]\n", current_buffer, (int)(current_buffer < this.first_ptr[1] ? 0 : 1));
+//  debug_printf("  read_bank_rd_ptr = %d, read_bank_wr_ptr = %d\n", this.read_bank_rd_ptr, this.read_bank_wr_ptr);
   int bn = current_buffer < this.first_ptr[1] ? 0 : 1;
   set(this.wr_ptr[bn]-4, length);                          // record length of current packet.
   this.wr_ptr[bn] = this.wr_ptr[bn] + ((length+3)&~3) + 4; // new end pointer.
@@ -309,10 +327,33 @@ void mii_lite_restart_buffer(struct mii_lite_data_t &this) {
       this.next_buffer = this.wr_ptr[bn];              // if so, record packet pointer
     }
   }
+
+  if(this.next_buffer != -1)
+  {
+      // Log which bank this packet was written to
+      unsigned new_read_bank_wr_ptr = increment_and_wrap_power_of_2(this.read_bank_wr_ptr, 32);
+
+      // If the pointers have overflowed the 32 slots then
+      // drop the packet.
+      if (this.read_bank_rd_ptr == new_read_bank_wr_ptr) {
+        this.next_buffer = -1;
+        this.refill_bank_number = bn;
+        return;
+      }
+
+      this.read_bank &= ~(1 << this.read_bank_wr_ptr);
+      this.read_bank |= bn << this.read_bank_wr_ptr;
+      this.read_bank_wr_ptr = new_read_bank_wr_ptr;
+  }
 }
 
 #pragma unsafe arrays
 void mii_lite_free_in_buffer(struct mii_lite_data_t &this, char * unsafe base0) {
+//  debug_printf("mii_lite_free_in_buffer(%x) [bank = %d]\n", base0, base0 < this.first_ptr[1] ? 0 : 1);
+//  debug_printf("  Bank 0: %x - %x|%x\n", this.first_ptr[0], this.last_safe_ptr[0], this.first_ptr[1] - 4);
+//  debug_printf("  Bank 1: %x - %x|%x\n", this.first_ptr[1], this.last_safe_ptr[1], this.last_safe_ptr[1] + MAXPACKET/4 - 4);
+  if(base0)
+  {
       unsafe {
         int base = (int) base0;
         int bank_number = base < this.first_ptr[1] ? 0 : 1;
@@ -320,7 +361,9 @@ void mii_lite_free_in_buffer(struct mii_lite_data_t &this, char * unsafe base0)
         base -= 4;
         set(base-4, -get(base-4));
         while (1) {
+//          debug_printf("  free_ptr = %x\n", this.free_ptr[bank_number]);
           int l = get(this.free_ptr[bank_number]);
+//          debug_printf("    l = %d\n", l);
           if (l > 0) {
             break;
           }
@@ -333,6 +376,8 @@ void mii_lite_free_in_buffer(struct mii_lite_data_t &this, char * unsafe base0)
         }
         // Note - wrptr may have been stuck
       }
+  }
+
   mii_lite_restart_buffer(this);
 }
Post Reply