[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

[Kieran Mansley]

On Fri, 2009-06-26 at 11:11 +0200, patrick Deflandre wrote:

> <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()

It looks like the packet is getting a good way through the stack - as
far as the netif->output() call, so it's done all the UDP and IP parts
without any problem. I'm not sure what this function pointer will be
set to in your project, but typically this will be something like
etherarp_output(). I would debug what is going on there. As lwIP is
also failing to respond to the ARP query, I suspect there might be a
problem with ARP. If not that, then you're into your driver.

Kieran

_______________________________________________
lwip-users mailing list
lwip-...@nongnu.org
http://lists.nongnu.org/mailman/listinfo/lwip-users

[Bill Auerbach]

Could it be the checksum error?

[patrick Deflandre]

Hello Kieran,

I check for netif->output, and as you say, it is set to
etherarp_output.

But I don't really understand why you say lwIP is failing to respond
to the ARP query. If you means lwIP can't respond to ARP request from
an another host on the net, you make a mistake. My application works
successfuly in tcp mode.

But as you say, I wonder if lwIP does manage correctly an ARP request
from the host itself. I add some trace on lwIP, which give :

######################### TRACE BEGIN ######################

<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>etharp_timeretharp_timeretharp_timeretharp_timeretharp_timer

update_arp_entry()update_arp_entry: 133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>find_entry: found empty entry 0
<LF>find_entry: selecting empty entry 0
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.update_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.etharp_ip_input: updating ETHARP
table.update_arp_entry()update_arp_entry: 133.38.20.50 - 00:1e:
4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>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 | 35 | (v, hl, tos, len)
<LF>+-------------------------------+| 20388 |010| 0 |
(id, flags, offset)
<LF>+-------------------------------+| 64 | 17 | 0xb811 |
(ttl, proto, chksum)
<LF>+-------------------------------+| 133 | 38 | 20 | 50 |
(src)
<LF>+-------------------------------+| 133 | 38 | 20 | 150 |
(dest)
<LF>+-------------------------------+ip_input: p->len 35 p->tot_len 35
<LF>udp_input: received datagram of length 15

<LF>UDP header:+-------------------------------+| 41486
| 69 | (src port, dest port)

<LF>+-------------------------------+| 15 | 0xea21 |

(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 checksum-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>udp_sendudp_send: added header in given pbuf 215bf0
<LF>udp_send: sending datagram of length 15
<LF>udp_send: UDP packet length 15
<LF>udp_send: UDP checksum 0x21ea

<LF>udp_send: ip_output_if (,,,,IP_PROTO_UDP,)ip_output_if: em0
<LF>IP header:+-------------------------------+| 4 | 5 | 0x00

| 35 | (v, hl, tos, len)

<LF>+-------------------------------+| 0 |000| 0 |
(id, flags, offset)

<LF>+-------------------------------+| 64 | 17 | 0x47b6 |

(ttl, proto, chksum)
<LF>+-------------------------------+| 133 | 38 | 20 | 150 |
(src)
<LF>+-------------------------------+| 133 | 38 | 20 | 50 |
(dest)

<LF>+-------------------------------+netif->output()find_entry: found
empty entry 1
<LF>find_entry: selecting empty entry 1
<LF>etharp_request: sending ARP request.etharp_raw: sending raw ARP
packet.etharp_query: queued packet 215bf0 on ARP entry 1
<LF>-D- udpecho_thread - get clonck

<LF>
<LF><CR>-D- udpecho_thread - delete
<LF><CR>-D- udpecho_thread - recv

<LF><CR>update_arp_entry()update_arp_entry: 133.38.20.50 - 00:1e:
4f:d1:2c:d5
<LF>find_entry: found matching stable entry 0
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.update_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.update_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.etharp_timerupdate_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.etharp_timeretharp_timer: expired pending entry
1.
<LF>etharp_timer: freeing entry 1, packet queue 214ee0.
<LF>etharp_timerupdate_arp_entry()update_arp_entry: 133.38.20.50 -
00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.update_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.update_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.etharp_timerupdate_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.update_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.update_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.update_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.update_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP
request was not for us.etharp_timerupdate_arp_entry()update_arp_entry:
133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0

######################### TRACE END ######################

I dont find anything which seems wrong to me.
A packet is send by the arp request. But I wonder why the ARP request
I see on the wireshark log is from 133.38.20.150 to 133.38.20.150 as
in the ip header the destination is set to 133.38.20.50

Is this what it is expected ?


Thank for your help.
Patrick

> lwip-us...@nongnu.orghttp://lists.nongnu.org/mailman/listinfo/lwip-users

[patrick Deflandre]

I am wondering too why my linux station send bad checksum on a few ip
frame. I don't know if it change something on my problem, but I should
investigate on that problem too.

Nevertheless, as the udp frame seem to be received by the target, I
don't think this is the problem for sending an udp frame from the
embedded lwIP to my linux station.

Does anybody knows about linux bad checksum of ip frame ?

[patrick Deflandre]

Hello Kieran,

I check for netif->output, and as you say, it is set to
etherarp_output.

But I don't really understand why you say lwIP is failing to respond
to the ARP query. If you means lwIP can't respond to ARP request from
an another host on the net, you make a  mistake. My application works
successfuly in tcp mode.

But as you say, I wonder if lwIP does manage correctly an ARP request
from the host itself. I add some trace on lwIP, which give :

######################### TRACE  BEGIN ######################

<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>etharp_timeretharp_timeretharp_timeretharp_timeretharp_timer

update_arp_entry()update_arp_entry: 133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>find_entry: found empty entry 0
<LF>find_entry: selecting empty entry 0
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP request was not for us.update_arp_entry()update_arp_entry: 133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0
<LF>etharp_arp_input: incoming ARP requestetharp_arp_input: ARP request was not for us.etharp_ip_input: updating ETHARP table.update_arp_entry()update_arp_entry: 133.38.20.50 - 00:1e:4f:d1:2c:d5
<LF>update_arp_entry: updating stable entry 0

<LF>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 |        35     | (v, hl, tos, len)
<LF>+-------------------------------+|    20388      |010|       0   | (id, flags, offset)
<LF>+-------------------------------+|   64  |   17  |    0xb811     | (ttl, proto, chksum)

<LF>+-------------------------------+|  133  |   38  |   20  |   50  | (src)
<LF>+-------------------------------+|  133  |   38  |   20  |  150  | (dest)

<LF>+-------------------------------+ip_input: p->len 35 p->tot_len 35
<LF>udp_input: received datagram of length 15

<LF>UDP header:+-------------------------------+|     41486     |        69     | (src port, dest port)

<LF>+-------------------------------+|        15     |     0xea21    | (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 checksum-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>udp_sendudp_send: added header in given pbuf 215bf0
<LF>udp_send: sending datagram of length 15

<LF>udp_send: UDP packet length 15
<LF>udp_send: UDP checksum 0x21ea

<LF>udp_send: ip_output_if (,,,,IP_PROTO_UDP,)ip_output_if: em0

<LF>IP header:+-------------------------------+| 4 | 5 |  0x00 |        35     | (v, hl, tos, len)

<LF>+-------------------------------+|        0      |000|       0   | (id, flags, offset)

<LF>+-------------------------------+|   64  |   17  |    0x47b6     | (ttl, proto, chksum)

<LF>+-------------------------------+|  133  |   38  |   20  |  150  | (src)
<LF>+-------------------------------+|  133  |   38  |   20  |   50  | (dest)

<LF>+-------------------------------+netif->output()find_entry: found empty entry 1
<LF>find_entry: selecting empty entry 1
<LF>etharp_request: sending ARP request.etharp_raw: sending raw ARP packet.etharp_query: queued packet 215bf0 on ARP entry 1
<LF>-D- udpecho_thread - get clonck

<LF>
<LF><CR>-D- udpecho_thread - delete
<LF><CR>-D- udpecho_thread - recv

2009/6/26 Kieran Mansley <kie...@recoil.org>

[patrick Deflandre]

I am wondering too why my linux station send bad checksum on a few ip
frame. I don't know if it change something on my problem, but I should
investigate on that problem too.

Nevertheless, as the udp frame seem to be received by the target, I
don't think this is the problem for sending an udp frame from the
embedded lwIP to my linux station.

Does anybody knows about linux bad checksum of ip frame ?

2009/6/26 Bill Auerbach <baue...@arrayonline.com>

[Kieran Mansley]

On Mon, 2009-06-29 at 14:05 +0200, patrick Deflandre wrote:
> Hello Kieran,
>
>
> I check for netif->output, and as you say, it is set to
> etherarp_output.

So I think you should investigate what happens to the packet once it
gets there.

> But I don't really understand why you say lwIP is failing to respond
> to the ARP query. If you means lwIP can't respond to ARP request from
> an another host on the net, you make a mistake. My application works
> successfuly in tcp mode.

I misunderstood: I thought the ARP was for the target from the PC, but I
see now that it looks like it is the target sending an ARP request for
its own address.

> But as you say, I wonder if lwIP does manage correctly an ARP request
> from the host itself. I add some trace on lwIP, which give :

[snip]

> Is this what it is expected ?

Not sure: I find it really hard to go through text output of packet
captures rather than being able to work through the capture in wireshark
itself. Could you attach a pcap file instead?

[Yoshiki Komatsudaira]

I don't think the UDP checksum is invalid.
It maybe come from "Checksum offloading".
http://www.wireshark.org/docs/wsug_html_chunked/ChAdvChecksums.html

Subject: Re: [lwip-users] UDP packet sending problem
From: patrick Deflandre

[patrick Deflandre]

So I give you 4 files for 2 tests.

1 )  The first set is for a tcp connection : tcp_test.pcap , tcp_test.trace.txt.

It is a short connection which is made after a power on of the lwip target. The pc is 133.38.20.50 and the embedded target is 133.38.20.150. We can see the target is responding to the pc arp request.

2)  The second set is for an udp echo test. udp_echo.pcap , udp_echo.trace.txt

It is a short udp request carrying only "ping" data, on which the embeded should simply reply with the same data. We can see the pc arp request, then the udp packet flow from pc to target. But there is after that this Gratuitous arp request from the embedded target to the pc station and no other transmission.

For the two example, I have use a simple net connecting only the pc to the target, but as the pc was previously connect to the lan, there are some garbage requests to the other parts of the lan.

And the xxx.trace.txt contains the application trace output for the communication tests.

Nevertheless, I tried to understand what can happen to the arp request.

Thank a lot for your help.
Patrick.

2009/6/29 Kieran Mansley <kie...@recoil.org>

[patrick Deflandre]

2009/6/29 Yoshiki Komatsudaira <kom...@bug.co.jp>

I don't think the UDP checksum is invalid.
It maybe come from "Checksum offloading".
http://www.wireshark.org/docs/wsug_html_chunked/ChAdvChecksums.html

I think this is the most likely explanation of the checksum error reported by wireshark. None of the packet are compliant with the tftp protocol. This will surely make wireshark in trouble when checking an expected checksum...

Defenitivily, it must not be the reason of my udp sending problem.
Many thanks for the link.

Patrick.

[Kieran Mansley]

On Mon, 2009-06-29 at 15:16 +0200, patrick Deflandre wrote:
> So I give you 4 files for 2 tests.
>
> 1 ) The first set is for a tcp connection : tcp_test.pcap ,
> tcp_test.trace.txt.

Looks fine.

> 2) The second set is for an udp echo test. udp_echo.pcap ,
> udp_echo.trace.txt

One thing I notice when comparing the two captures is that the second
has a lot of other ARP traffic in it. I wonder if that could be part of
the problem. I don't know why this features in the UDP capture and not
the TCP one.

As the trace file showed that the UDP reply is being sent by the stack
and getting as far as etharp_output() I think this has got to be where
things go wrong. The gratuitous ARP also points to an ARP problem too.
By adding some tracing to that function you should be able to quickly
see what's going on.

[Kieran Mansley]

On Mon, 2009-06-29 at 15:41 +0200, patrick Deflandre wrote:
>
>
> 2009/6/29 Yoshiki Komatsudaira <kom...@bug.co.jp>
> I don't think the UDP checksum is invalid.
> It maybe come from "Checksum offloading".
> http://www.wireshark.org/docs/wsug_html_chunked/ChAdvChecksums.html
>
>
> I think this is the most likely explanation of the checksum error
> reported by wireshark.

I'm not convinced: the TCP packets in your other capture show the
correct checksum, and you would expect them to have the wrong checksum
if checksum offloading was happening. On the other hand, the checksum
in the text debug trace of the UDP application is different to the one
in the UDP packet capture, and so something has filled it in correctly,
so maybe checksum offload is happening.

> None of the packet are compliant with the tftp protocol. This will
> surely make wireshark in trouble when checking an expected checksum...

No: the UDP checksum is independent of the next protocol layer, and so
won't care if the TFTP bit is correct or not.

> Defenitivily, it must not be the reason of my udp sending problem.

It is not your problem for sure, as lwIP receives the UDP packet, thinks
the checksum is correct, and sends a response. The response gets lots
somewhere in etharp_output() before making it onto the network though.

I notice that in the udp_echo.trace.txt there is the following:

<LF>find_entry: selecting empty entry 1
<LF>etharp_request: sending ARP request.etharp_raw: sending raw ARP
packet.etharp_query: queued packet 215bf0 on ARP entry 1

This is odd for two reasons: (i) it should already have an entry for the
PC's MAC address as it's updated that entry lots already from the other
ARP requests seen on the network earlier; and (ii) the packet it sends
is not an ARP request for the PC's MAC, but a gratuitous ARP of its own
MAC. I think there is definitely something going wrong here.

Do you have ARP_QUEUEING on?

Kieran

[patrick Deflandre]

2009/6/29 Kieran Mansley <kie...@recoil.org>

On Mon, 2009-06-29 at 15:16 +0200, patrick Deflandre wrote:

> 2)  The second set is for an udp echo test. udp_echo.pcap ,
> udp_echo.trace.txt

One thing I notice when comparing the two captures is that the second
has a lot of other ARP traffic in it.  I wonder if that could be part of
the problem.  I don't know why this features in the UDP capture and not
the TCP one.

I think not. I have some trace where this very few ARP traffic, and the udp sending is not working.
This ARP traffic is due to my bad configuration, where I switch from LAN to direct wiring between my target and PC for isolating the traffic. But the PC still try some connection even after disconnecting.

As the trace file showed that the UDP reply is being sent by the stack
and getting as far as etharp_output() I think this has got to be where
things go wrong.  The gratuitous ARP also points to an ARP problem too.
By adding some tracing to that function you should be able to quickly
see what's going on.

I will add some tracing there.

Many thanks for your help.
Patrick
 

[patrick Deflandre]

2009/6/29 Kieran Mansley <kie...@recoil.org>

On Mon, 2009-06-29 at 15:41 +0200, patrick Deflandre wrote:

> None of the packet are compliant with the tftp protocol. This will
> surely make wireshark in trouble when checking an expected checksum...

No: the UDP checksum is independent of the next protocol layer, and so
won't care if the TFTP bit is correct or not.

I was wrong, Thank for the precision.
 

I notice that in the udp_echo.trace.txt there is the following:

<LF>find_entry: selecting empty entry 1
<LF>etharp_request: sending ARP request.etharp_raw: sending raw ARP
packet.etharp_query: queued packet 215bf0 on ARP entry 1

This is odd for two reasons: (i) it should already have an entry for the
PC's MAC address as it's updated that entry lots already from the other
ARP requests seen on the network earlier; and (ii) the packet it sends
is not an ARP request for the PC's MAC, but a gratuitous ARP of its own
MAC.  I think there is definitely something going wrong here.

Do you have ARP_QUEUEING on?

Yes, I have ARP_QUEUEING on. But I did not bother until now. Is this good or not ? Should I change this value ?

[patrick Deflandre]

2009/6/29 Kieran Mansley <kie...@recoil.org>

It is not your problem for sure, as lwIP receives the UDP packet, thinks
the checksum is correct, and sends a response.  The response gets lots
somewhere in etharp_output() before making it onto the network though.

I notice that in the udp_echo.trace.txt there is the following:

<LF>find_entry: selecting empty entry 1
<LF>etharp_request: sending ARP request.etharp_raw: sending raw ARP
packet.etharp_query: queued packet 215bf0 on ARP entry 1

This is odd for two reasons: (i) it should already have an entry for the
PC's MAC address as it's updated that entry lots already from the other
ARP requests seen on the network earlier; and (ii) the packet it sends
is not an ARP request for the PC's MAC, but a gratuitous ARP of its own
MAC.  I think there is definitely something going wrong here.

So I find where it was not working. I will try to explain why it doesn't work, sorry if it  is not as clear as it should but my English is a bit poor...

As you said, the response was lost somewhere in etharp_output. This is actually done in ip_output_if (file src/core/ipv4/ip.c line 510) because lwIP then write the destination ip in the ip header with the use of the pointer dest.

This pointer was obtained at the beginning of the process by the function and macro use :
    buf = netconn_recv(conn);
    addr = netbuf_fromaddr(buf);

addr is a copy of the buf->addr which is pointing on the source ip header field. The buf is created by the netconn_recv call.

We use addr to connect to the remote port with netconn_connect(conn, addr, port)
But if we don't set this buf->addr to NULL , then it will be used by the do_send function (src/api/api_msg.c line 881) to send the packet.

But as buf->addr is a pointer to the source ip header, this value will be overwrite by ip_output_if when writing the new source in the new header ip (file src/core/ipv4/ip.c line 510). So the dest in this function which is use at the end on the call netif->output(netif, p, dest) will be in fact the source ip. It then result on an ARP gratuitous request which is never reply and a lost of the packet.

So here is the solution :
===================

Add a line in the contrib/ports/unix/proj/unixsim/apps/udpecho.c example which set buf->addr to NULL :

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];
 
  conn = netconn_new(NETCONN_UDP);
  netconn_bind(conn, NULL, 7);

  while (1) {
    buf = netconn_recv(conn);
    addr = netbuf_fromaddr(buf);
    port = netbuf_fromport(buf);
    netconn_connect(conn, addr, port);

    netbuf_copy(buf, buffer, buf->p->tot_len);

    buffer[buf->p->tot_len] = '\0';

   buf->addr = NULL; // we must set addr to NULL, because addr is a pointer on the source ip header which
                      // will be overwrite by ip_output_if function. This lead to an ARP gratuitous request
                      // and a failure to send the buf.
                      // if we set buf-addr to NULL, then we force the do_send function to use the
                      // udp_send which then will use the pcb->remote_ip destination ip

    netconn_send(conn, buf);

    printf("got %s\n", buffer);

    netbuf_delete(buf);
  }
}


I didn't try to compile and test this example on a Linux station, but it does'nt work without this modification on my embedded target.

If you have any suggestions on what should be better to do, please let me know.

Thanks to Kieran for it's very valuated help.

Patrick.