[lwip-users] UDP packet sending problem

[patrick Deflandre]

Hello,

First, I had to say that this is my first post on this list, and I wish to introduce myself.

I am an electronic engineer and I work on a project which use FreeRTOS and Lwip v 1.3.0. This project use a specific design which is made on an atmel AT91SAM7X512 and a IDT ICS 1893 for the PHY layer. The project is build on a Linux station and I use GCC, openocd and Eclipse. 

Today, I am stuck on an UDP problem and I want to ask you for advice.

The project has been built on a FreeRTOS demo v4.2.0 which have been upgrade to v5.0.2. As the same, the lwip have been upgrade from the 1.1.0 to 1.3.0.

I have put on my project some kind of TCP servers which are well working. But I want now to add a TFTP server and I must use UDP. I first try to use socket as there is a TFTP demo on FreeRTOS which use it. As it was not working, I then try to test more trivial example and I switch back to netconn API. I then try to use the lwip contrib udpecho.c example. I copy this example in my project but I can't received any udp echo.

I have enabled some lwip trace (API_LIB_DEBUG, UDP_DEBUG and IP_DEBUG) and I think the lwip stack is trying to send back the echo, but there is something that is not working. I first think for a timer problem, but I can't find where It can be.

The test is base on a udp packet send from a pc (133.38.20.50)  to a target (133.38.20.150) tfpt port (69) which contain the data "ping"

I give you my code :

/*-----------------------------------------------------------------------------------*/
void udpecho_thread(void *arg);
void
udpecho_thread(void *arg)
{
  static struct netconn *conn;
  static struct netbuf *buf;
  static struct ip_addr *addr;
  static unsigned short port;
  //char buffer[4096];

  (void) arg;

    // on attend que l'interface soit montée
    //while (xEthInterfaceIsUp != pdTRUE)
    while (! netif_is_up(&EMAC_if))
        vTaskDelay(BLOCK_100ms);
    trace_LOG(trace_DEBUG, "running...\n\r");

    trace_LOG(trace_DEBUG, "netconn_new\n\r");
  conn = netconn_new(NETCONN_UDP);
    trace_LOG(trace_DEBUG, "bind\n\r");
  netconn_bind(conn, NULL, tftp_PORT);

  while (1) {
        trace_LOG(trace_DEBUG, "recv\n\r");
    buf = netconn_recv(conn);
    trace_LOG(trace_DEBUG, "fromaddr\n\r");
    addr = netbuf_fromaddr(buf);
    trace_LOG(trace_DEBUG, "fromport\n\r");
    port = netbuf_fromport(buf);
    trace_LOG(trace_DEBUG, "connect\n\r");
    netconn_connect(conn, addr, port);
    trace_LOG(trace_DEBUG, "copy\n\r");
    netbuf_copy(buf, buffer, buf->p->tot_len);
    trace_LOG(trace_DEBUG, "delimiter\n\r");
    buffer[buf->p->tot_len] = '\0';
    trace_LOG(trace_DEBUG, "send\n\r");
    netconn_send(conn, buf);
    //printf("got %s\n", buffer);
    trace_LOG(trace_DEBUG, "get %s\n\r", buffer);
    trace_LOG(trace_DEBUG, "delete\n\r");
    netbuf_delete(buf);
  }
}
/*-----------------------------------------------------------------------------------*/
void
udpecho_init(void)
{
    if (sys_thread_new("udpecho_d", udpecho_thread, (void *) NULL, TCP_SERVER_STACK_SIZE + 100, TCP_SERVER_PRIORITY ) == NULL)
            while (1);

}


And the trace it produced :

<LF><CR>-D- udpecho_thread - running...
<LF><CR>-D- udpecho_thread - netconn_new
<LF><CR>-D- udpecho_thread - bind
<LF><CR>udp_bind(ipaddr = 0.0.0.0, port = 69)
<LF>udp_bind: bound to 0.0.0.0, port 69
<LF>-D- udpecho_thread - recv
<LF><CR>ip_input: iphdr->dest 0x96142685 netif->ip_addr 0x96142685 (0x2685, 0x2685, 0x96140000)
<LF>ip_input: packet accepted on interface em
<LF>ip_input: IP header:+-------------------------------+| 4 | 5 |  0x00 |        33     | (v, hl, tos, len)
<LF>+-------------------------------+|    20372      |010|       0   | (id, flags, offset)
<LF>+-------------------------------+|   64  |   17  |    0xb823     | (ttl, proto, chksum)
<LF>+-------------------------------+|  133  |   38  |   20  |   50  | (src)
<LF>+-------------------------------+|  133  |   38  |   20  |  150  | (dest)
<LF>+-------------------------------+ip_input: p->len 33 p->tot_len 33
<LF>udp_input: received datagram of length 13
<LF>UDP header:+-------------------------------+|     41486     |        69     | (src port, dest port)
<LF>+-------------------------------+|        13     |     0x419b    | (len, chksum)
<LF>+-------------------------------+udp (133.38.20.150, 69) <-- (133.38.20.50, 41486)
<LF>pcb (0.0.0.0, 69) --- (0.0.0.0, 0)
<LF>udp_input: calculating checksumnetconn_recv: received -D- udpecho_thread - fromaddr
<LF><CR>-D- udpecho_thread - fromport
<LF><CR>-D- udpecho_thread - connect
<LF><CR>udp_connect: connected to 133.38.20.50,port 41486
<LF>-D- udpecho_thread - copy
<LF><CR>-D- udpecho_thread - delimiter
<LF><CR>-D- udpecho_thread - send
<LF><CR>netconn_send: sending 5 bytes
<LF>netconn_send: dst = 32142685
<LF><CR>netconn_send: port = a20e
<LF><CR>udp_sendudp_send: added header in given pbuf _STRING_SIZE
<LF><CR>udp_send: sending datagram of length 13
<LF>udp_send: UDP packet length 13
<LF>udp_send: UDP checksum 0x9b41
<LF>udp_send: ip_output_if (,,,,IP_PROTO_UDP,)ip_output_if: em0
<LF>IP header:+-------------------------------+| 4 | 5 |  0x00 |        33     | (v, hl, tos, len)
<LF>+-------------------------------+|        0      |000|       0   | (id, flags, offset)
<LF>+-------------------------------+|   64  |   17  |    0x47b8     | (ttl, proto, chksum)
<LF>+-------------------------------+|  133  |   38  |   20  |  150  | (src)
<LF>+-------------------------------+|  133  |   38  |   20  |   50  | (dest)
<LF>+-------------------------------+netif->output()-D- udpecho_thread - get ping
<LF>
<LF><CR>-D- udpecho_thread - delete
<LF><CR>-D- udpecho_thread - recv
<LF><CR>



the lwip statistic output :

<LF><CR>
<LF>LINK
<LF><HT>xmit: 1
<LF><HT>rexmit: 0
<LF><HT>recv: 68
<LF><HT>fw: 0
<LF><HT>drop: 0
<LF><HT>chkerr: 0
<LF><HT>lenerr: 0
<LF><HT>memerr: 0
<LF><HT>rterr: 0
<LF><HT>proterr: 0
<LF><HT>opterr: 0
<LF><HT>err: 0
<LF><HT>cachehit: 0
<LF>
<LF>ETHARP
<LF><HT>xmit: 1
<LF><HT>rexmit: 0
<LF><HT>recv: 33
<LF><HT>fw: 0
<LF><HT>drop: 0
<LF><HT>chkerr: 0
<LF><HT>lenerr: 0
<LF><HT>memerr: 0
<LF><HT>rterr: 0
<LF><HT>proterr: 0
<LF><HT>opterr: 0
<LF><HT>err: 0
<LF><HT>cachehit: 32
<LF>
<LF>IP_FRAG
<LF><HT>xmit: 0
<LF><HT>rexmit: 0
<LF><HT>recv: 0
<LF><HT>fw: 0
<LF><HT>drop: 0
<LF><HT>chkerr: 0
<LF><HT>lenerr: 0
<LF><HT>memerr: 0
<LF><HT>rterr: 0
<LF><HT>proterr: 0
<LF><HT>opterr: 0
<LF><HT>err: 0
<LF><HT>cachehit: 0
<LF>
<LF>IP
<LF><HT>xmit: 1
<LF><HT>rexmit: 0
<LF><HT>recv: 1
<LF><HT>fw: 0
<LF><HT>drop: 0
<LF><HT>chkerr: 0
<LF><HT>lenerr: 0
<LF><HT>memerr: 0
<LF><HT>rterr: 0
<LF><HT>proterr: 0
<LF><HT>opterr: 0
<LF><HT>err: 0
<LF><HT>cachehit: 0
<LF>
<LF>ICMP
<LF><HT>xmit: 0
<LF><HT>rexmit: 0
<LF><HT>recv: 0
<LF><HT>fw: 0
<LF><HT>drop: 0
<LF><HT>chkerr: 0
<LF><HT>lenerr: 0
<LF><HT>memerr: 0
<LF><HT>rterr: 0
<LF><HT>proterr: 0
<LF><HT>opterr: 0
<LF><HT>err: 0
<LF><HT>cachehit: 0
<LF>
<LF>UDP
<LF><HT>xmit: 1
<LF><HT>rexmit: 0
<LF><HT>recv: 1
<LF><HT>fw: 0
<LF><HT>drop: 0
<LF><HT>chkerr: 0
<LF><HT>lenerr: 0
<LF><HT>memerr: 0
<LF><HT>rterr: 0
<LF><HT>proterr: 0
<LF><HT>opterr: 0
<LF><HT>err: 0
<LF><HT>cachehit: 0
<LF>
<LF>TCP
<LF><HT>xmit: 0
<LF><HT>rexmit: 0
<LF><HT>recv: 0
<LF><HT>fw: 0
<LF><HT>drop: 0
<LF><HT>chkerr: 0
<LF><HT>lenerr: 0
<LF><HT>memerr: 0
<LF><HT>rterr: 0
<LF><HT>proterr: 0
<LF><HT>opterr: 0
<LF><HT>err: 0
<LF><HT>cachehit: 0
<LF>
<LF>MEM HEAP
<LF><HT>avail: 1600
<LF><HT>used: 20
<LF><HT>max: 104
<LF><HT>err: 0
<LF>
<LF>MEM RAW_PCB
<LF><HT>avail: 4
<LF><HT>used: 0
<LF><HT>max: 0
<LF><HT>err: 0
<LF>
<LF>MEM UDP_PCB
<LF><HT>avail: 4
<LF><HT>used: 1
<LF><HT>max: 1
<LF><HT>err: 0
<LF>
<LF>MEM TCP_PCB
<LF><HT>avail: 5
<LF><HT>used: 0
<LF><HT>max: 1
<LF><HT>err: 0
<LF>
<LF>MEM TCP_PCB_LISTEN
<LF><HT>avail: 8
<LF><HT>used: 1
<LF><HT>max: 1
<LF><HT>err: 0
<LF>
<LF>MEM TCP_SEG
<LF><HT>avail: 16
<LF><HT>used: 0
<LF><HT>max: 0
<LF><HT>err: 0
<LF>
<LF>MEM REASSDATA
<LF><HT>avail: 5
<LF><HT>used: 0
<LF><HT>max: 0
<LF><HT>err: 0
<LF>
<LF>MEM NETBUF
<LF><HT>avail: 4
<LF><HT>used: 0
<LF><HT>max: 1
<LF><HT>err: 0
<LF>
<LF>MEM NETCONN
<LF><HT>avail: 8
<LF><HT>used: 2
<LF><HT>max: 2
<LF><HT>err: 0
<LF>
<LF>MEM TCPIP_MSG_API
<LF><HT>avail: 8
<LF><HT>used: 0
<LF><HT>max: 0
<LF><HT>err: 0
<LF>
<LF>MEM TCPIP_MSG_INPKT
<LF><HT>avail: 8
<LF><HT>used: 0
<LF><HT>max: 1
<LF><HT>err: 0
<LF>
<LF>MEM ARP_QUEUE
<LF><HT>avail: 30
<LF><HT>used: 0
<LF><HT>max: 1
<LF><HT>err: 0
<LF>
<LF>MEM SYS_TIMEOUT
<LF><HT>avail: 5
<LF><HT>used: 3
<LF><HT>max: 3
<LF><HT>err: 0
<LF>
<LF>MEM PBUF_REF/ROM
<LF><HT>avail: 16
<LF><HT>used: 0
<LF><HT>max: 0
<LF><HT>err: 0
<LF>
<LF>MEM PBUF_POOL
<LF><HT>avail: 16
<LF><HT>used: 0
<LF><HT>max: 1
<LF><HT>err: 0
<LF>


And last, the wireshark log :

No.     Time            Source                Destination           Protocol Info
      1 10:07:34.033002 133.38.20.50          133.38.20.150         TFTP     Unknown (0x7069)

Frame 1 (47 bytes on wire, 47 bytes captured)
    Arrival Time: Jun 26, 2009 10:07:34.033002000
    [Time delta from previous captured frame: 0.000000000 seconds]
    [Time delta from previous displayed frame: 0.000000000 seconds]
    [Time since reference or first frame: 0.000000000 seconds]
    Frame Number: 1
    Frame Length: 47 bytes
    Capture Length: 47 bytes
    [Frame is marked: False]
    [Protocols in frame: eth:ip:udp:tftp]
    [Coloring Rule Name: Checksum Errors]
    [Coloring Rule String: cdp.checksum_bad==1 || edp.checksum_bad==1 || ip.checksum_bad==1 || tcp.checksum_bad==1 || udp.checksum_bad==1]
Ethernet II, Src: Dell_d1:2c:d5 (00:1e:4f:d1:2c:d5), Dst: 00:bd:33:06:68:22 (00:bd:33:06:68:22)
    Destination: 00:bd:33:06:68:22 (00:bd:33:06:68:22)
        Address: 00:bd:33:06:68:22 (00:bd:33:06:68:22)
        .... ...0 .... .... .... .... = IG bit: Individual address (unicast)
        .... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
    Source: Dell_d1:2c:d5 (00:1e:4f:d1:2c:d5)
        Address: Dell_d1:2c:d5 (00:1e:4f:d1:2c:d5)
        .... ...0 .... .... .... .... = IG bit: Individual address (unicast)
        .... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
    Type: IP (0x0800)
Internet Protocol, Src: 133.38.20.50 (133.38.20.50), Dst: 133.38.20.150 (133.38.20.150)
    Version: 4
    Header length: 20 bytes
    Differentiated Services Field: 0x00 (DSCP 0x00: Default; ECN: 0x00)
        0000 00.. = Differentiated Services Codepoint: Default (0x00)
        .... ..0. = ECN-Capable Transport (ECT): 0
        .... ...0 = ECN-CE: 0
    Total Length: 33
    Identification: 0x4f94 (20372)
    Flags: 0x04 (Don't Fragment)
        0... = Reserved bit: Not set
        .1.. = Don't fragment: Set
        ..0. = More fragments: Not set
    Fragment offset: 0
    Time to live: 64
    Protocol: UDP (0x11)
    Header checksum: 0xb823 [correct]
        [Good: True]
        [Bad : False]
    Source: 133.38.20.50 (133.38.20.50)
    Destination: 133.38.20.150 (133.38.20.150)
User Datagram Protocol, Src Port: 41486 (41486), Dst Port: tftp (69)
    Source port: 41486 (41486)
    Destination port: tftp (69)
    Length: 13
    Checksum: 0x3333 [incorrect, should be 0x419b (maybe caused by "UDP checksum offload"?)]
        [Good Checksum: False]
        [Bad Checksum: True]
Trivial File Transfer Protocol
    Opcode: Unknown (28777)
    Data (3 bytes)

No.     Time            Source                Destination           Protocol Info
      2 10:07:34.071477 00:bd:33:06:68:22     Broadcast             ARP      Gratuitous ARP for 133.38.20.150 (Request)

Frame 2 (60 bytes on wire, 60 bytes captured)
    Arrival Time: Jun 26, 2009 10:07:34.071477000
    [Time delta from previous captured frame: 0.038475000 seconds]
    [Time delta from previous displayed frame: 0.038475000 seconds]
    [Time since reference or first frame: 0.038475000 seconds]
    Frame Number: 2
    Frame Length: 60 bytes
    Capture Length: 60 bytes
    [Frame is marked: False]
    [Protocols in frame: eth:arp]
    [Coloring Rule Name: ARP]
    [Coloring Rule String: arp]
Ethernet II, Src: 00:bd:33:06:68:22 (00:bd:33:06:68:22), Dst: Broadcast (ff:ff:ff:ff:ff:ff)
    Destination: Broadcast (ff:ff:ff:ff:ff:ff)
        Address: Broadcast (ff:ff:ff:ff:ff:ff)
        .... ...1 .... .... .... .... = IG bit: Group address (multicast/broadcast)
        .... ..1. .... .... .... .... = LG bit: Locally administered address (this is NOT the factory default)
    Source: 00:bd:33:06:68:22 (00:bd:33:06:68:22)
        Address: 00:bd:33:06:68:22 (00:bd:33:06:68:22)
        .... ...0 .... .... .... .... = IG bit: Individual address (unicast)
        .... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
    Type: ARP (0x0806)
    Trailer: 000000000000000000000000000000000000
Address Resolution Protocol (request/gratuitous ARP)
    Hardware type: Ethernet (0x0001)
    Protocol type: IP (0x0800)
    Hardware size: 6
    Protocol size: 4
    Opcode: request (0x0001)
    Sender MAC address: 00:bd:33:06:68:22 (00:bd:33:06:68:22)
    Sender IP address: 133.38.20.150 (133.38.20.150)
    Target MAC address: 00:00:00_00:00:00 (00:00:00:00:00:00)
    Target IP address: 133.38.20.150 (133.38.20.150)



The trace seems good for me, but we can see on the wireshark log that there is not any udp packet send from the target. I am asking too on the gratuitous arp request ? Why the target is making this request ?

And what can prevent the lwip stack to send UDP packet on the network ?

Any advice on what I should check will be greetly appreciated.

Patrick Deflandre