Re: [lwip-users] lwip 1.3 UDP - DNS strange behaviour

[Jonathan Larmour]

Sergio Sider wrote:
> Hi All,
> I turned on several DEBUG messages and waited for netif_is_up before
> call dns_gethostbyname, but the problem is present.
> I tried calling dns_gethostbyname 5 seconds AFTER the network
> interface is up and it worked, but I recall that in the past I still
> had problems sometimes, even with the delay.
> When using DHCP, there is no problem, even if I call dns_gethostbyname
> immediately after receiving the designated IP.
> 
> 
> Here are the logs of my application:

Can you enable DNS_DEBUG in lwipopts.h?

Are you using the tcpip thread? If you are unsure, then you can answer with
how you are initialising lwIP,and what value NO_SYS has in your lwipopts.h.

Jifl

> ================ without the explicit delay===================
> - No timeout occurs and the callback is never called
> - the dns UDP packet is not really sent, although the messages told me so
> 
> 
> 
> Powering SD-CARD socket
> Initialing I2C
> Initializing RTC Chip
> Loading config from E2PROM
> Configuring Systick
> Initializing Filesystem
> PRE-Loading ini defaults
> Trying to load IDC.INI
> Parsing inifile
> Inifile read ok!
> IDC.INI read!
> Openning IDC_CHAM.TXT for check
> Size = 2079296, 32489 records
> Verifying last 50 calls
> Openning IDC_AGEN.TXT for check
> Size = 98397, 1131 records
> End of file checking
> Mac Address = 00:1a:b6:00:03:b7
> initialing tcp/ip stack (IPADDR_USE_STATIC)
> dns_init: initializing
> udp_bind(ipaddr = 0.0.0.0, port = 0)
> udp_bind: bound to 0.0.0.0, port 4096
> netif_set_ipaddr: netif address being changed
> netif: IP address of interface lm set to 192.168.0.180
> netif: netmask of interface lm set to 255.255.255.0
> netif: GW address of interface lm set to 192.168.0.2
> netif: added interface lm IP addr 192.168.0.180 netmask 255.255.255.0
> gw 192.168.0.2
> netif: setting default interface lm
> find_entry: found empty entry 0
> find_entry: selecting empty entry 0
> etharp_request: sending ARP request.
> etharp_raw: sending raw ARP packet.
> initializing http server
> tcp_bind: bind to port 4321
> Setting UART2 for IDC serial
> Entering cooperative multitasking loop
> SNTP: ip address defined and interface is up!
> IP:    192.168.0.180
> MASK:  255.255.255.0
> GW:    192.168.0.2
> DNS1:  200.30.0.97
> DNS2:  200.204.0.10
> gethostbyname for host time.nist.gov
> dns_enqueue: "time.nist.gov": use DNS entry 0
> dns_send: dns_servers[0] "time.nist.gov": request
> udp_connect: connected to 200.30.0.97,port 53
> udp_send
> udp_send: added header in given pbuf 200015f8
> udp_send: sending datagram of length 39
> udp_send: UDP packet length 39
> inet_chksum_pseudo(): checksumming pbuf 200015f8 (has next 0)
> inet_chksum_pseudo(): pbuf chain lwip_chksum()=12c5
> udp_send: UDP checksum 0xed3a
> udp_send: ip_output_if (,,,,IP_PROTO_UDP,)
> ip_output_if: lm0
> IP header:
> +-------------------------------+
> | 4 | 5 |  0x00 |        59     | (v, hl, tos, len)
> +-------------------------------+
> |        0      |000|       0   | (id, flags, offset)
> +-------------------------------+
> |  255  |   17  |    0x31d6     | (ttl, proto, chksum)
> +-------------------------------+
> |  192  |  168  |    0  |  180  | (src)
> +-------------------------------+
> |  200  |   30  |    0  |   97  | (dest)
> +-------------------------------+
> netif->output()find_entry: found empty entry 1
> find_entry: selecting empty entry 1
> etharp_request: sending ARP request.
> etharp_raw: sending raw ARP packet.
> etharp_query: queued packet 200015f8 on ARP entry 1
> Initial response = -14
> [fa]IDCPC found on serial-port!
> [80][ea]IDCPC ready for lines 1-4
> udp_bind(ipaddr = 0.0.0.0, port = 0)
> udp_bind: bound to 0.0.0.0, port 4097
> udp_connect: connected to 192.168.0.255,port 1234
> udp_send
> udp_send: added header in given pbuf 200016cc
> udp_send: sending datagram of length 86
> udp_send: UDP packet length 86
> inet_chksum_pseudo(): checksumming pbuf 200016cc (has next 0)
> inet_chksum_pseudo(): pbuf chain lwip_chksum()=d5e7
> udp_send: UDP checksum 0x2a18
> udp_send: ip_output_if (,,,,IP_PROTO_UDP,)
> ip_output_if: lm0
> IP header:
> +-------------------------------+
> | 4 | 5 |  0x00 |       106     | (v, hl, tos, len)
> +-------------------------------+
> |        1      |000|       0   | (id, flags, offset)
> +-------------------------------+
> |  255  |   17  |    0x387e     | (ttl, proto, chksum)
> +-------------------------------+
> |  192  |  168  |    0  |  180  | (src)
> +-------------------------------+
> |  192  |  168  |    0  |  255  | (dest)
> +-------------------------------+
> netif->output()etharp_send_ip: sending packet 200016cc
> Sending BROADCAST ( 78) [01|0|  |  |                         |
> |192.168.000.180               | ]
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> etharp_timer
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> etharp_timer
> etharp_timer: expired pending entry 0.
> etharp_timer: expired pending entry 1.
> etharp_timer: freeing entry 1, packet queue 2000821c.
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> ...
> 
> 
> 
> ================ with explicit 5 seconds delay===================
> WORKED
> 
> 
> 
> Powering SD-CARD socket
> Initialing I2C
> Initializing RTC Chip
> Loading config from E2PROM
> Configuring Systick
> Initializing Filesystem
> PRE-Loading ini defaults
> Trying to load IDC.INI
> Parsing inifile
> Inifile read ok!
> IDC.INI read!
> Openning IDC_CHAM.TXT for check
> Size = 2079296, 32489 records
> Verifying last 50 calls
> Openning IDC_AGEN.TXT for check
> Size = 98397, 1131 records
> End of file checking
> Mac Address = 00:1a:b6:00:03:b7
> initialing tcp/ip stack (IPADDR_USE_STATIC)
> dns_init: initializing
> udp_bind(ipaddr = 0.0.0.0, port = 0)
> udp_bind: bound to 0.0.0.0, port 4096
> netif_set_ipaddr: netif address being changed
> netif: IP address of interface lm set to 192.168.0.180
> netif: netmask of interface lm set to 255.255.255.0
> netif: GW address of interface lm set to 192.168.0.2
> netif: added interface lm IP addr 192.168.0.180 netmask 255.255.255.0
> gw 192.168.0.2
> netif: setting default interface lm
> find_entry: found empty entry 0
> find_entry: selecting empty entry 0
> etharp_request: sending ARP request.
> etharp_raw: sending raw ARP packet.
> initializing http server
> tcp_bind: bind to port 4321
> Setting UART2 for IDC serial
> Entering cooperative multitasking loop
> SNTP: ip address defined and interface is up!
> IP:    192.168.0.180
> MASK:  255.255.255.0
> GW:    192.168.0.2
> DNS1:  200.30.0.97
> DNS2:  200.204.0.10
> [fa]IDCPC found on serial-port!
> [80][ea]IDCPC ready for lines 1-4
> udp_bind(ipaddr = 0.0.0.0, port = 0)
> udp_bind: bound to 0.0.0.0, port 4097
> udp_connect: connected to 192.168.0.255,port 1234
> udp_send
> udp_send: added header in given pbuf 200015f8
> udp_send: sending datagram of length 86
> udp_send: UDP packet length 86
> inet_chksum_pseudo(): checksumming pbuf 200015f8 (has next 0)
> inet_chksum_pseudo(): pbuf chain lwip_chksum()=d5e7
> udp_send: UDP checksum 0x2a18
> udp_send: ip_output_if (,,,,IP_PROTO_UDP,)
> ip_output_if: lm0
> IP header:
> +-------------------------------+
> | 4 | 5 |  0x00 |       106     | (v, hl, tos, len)
> +-------------------------------+
> |        0      |000|       0   | (id, flags, offset)
> +-------------------------------+
> |  255  |   17  |    0x387f     | (ttl, proto, chksum)
> +-------------------------------+
> |  192  |  168  |    0  |  180  | (src)
> +-------------------------------+
> |  192  |  168  |    0  |  255  | (dest)
> +-------------------------------+
> netif->output()etharp_send_ip: sending packet 200015f8
> Sending BROADCAST ( 78) [01|0|  |  |                         |
> |192.168.000.180               | ]
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> tcp_slowtmr: no active pcbs
> etharp_timer
> gethostbyname for host time.nist.gov
> dns_enqueue: "time.nist.gov": use DNS entry 0
> dns_send: dns_servers[0] "time.nist.gov": request
> udp_connect: connected to 200.30.0.97,port 53
> udp_send
> udp_send: added header in given pbuf 200015f8
> udp_send: sending datagram of length 39
> udp_send: UDP packet length 39
> inet_chksum_pseudo(): checksumming pbuf 200015f8 (has next 0)
> inet_chksum_pseudo(): pbuf chain lwip_chksum()=12c5
> udp_send: UDP checksum 0xed3a
> udp_send: ip_output_if (,,,,IP_PROTO_UDP,)
> ip_output_if: lm0
> IP header:
> +-------------------------------+
> | 4 | 5 |  0x00 |        59     | (v, hl, tos, len)
> +-------------------------------+
> |        1      |000|       0   | (id, flags, offset)
> +-------------------------------+
> |  255  |   17  |    0x31d5     | (ttl, proto, chksum)
> +-------------------------------+
> |  192  |  168  |    0  |  180  | (src)
> +-------------------------------+
> |  200  |   30  |    0  |   97  | (dest)
> +-------------------------------+
> netif->output()find_entry: found empty entry 1
> find_entry: selecting empty entry 1
> etharp_request: sending ARP request.
> etharp_raw: sending raw ARP packet.
> etharp_query: queued packet 200015f8 on ARP entry 1
> Initial response = -14
> update_arp_entry()
> update_arp_entry: 192.168.0.2 - 00:1b:2f:e6:74:a4
> find_entry: found matching pending entry 1
> update_arp_entry: updating stable entry 1
> etharp_send_ip: sending packet 20001668
> etharp_arp_input: incoming ARP reply
> dhcp_arp_reply()
> ip_input: iphdr->dest 0xb400a8c0 netif->ip_addr 0xb400a8c0 (0xa8c0,
> 0xa8c0, 0xb4000000)
> ip_input: packet accepted on interface lm
> ip_input:
> IP header:
> +-------------------------------+
> | 4 | 5 |  0x00 |       153     | (v, hl, tos, len)
> +-------------------------------+
> |    59434      |010|       0   | (id, flags, offset)
> +-------------------------------+
> |  247  |   17  |    0x114d     | (ttl, proto, chksum)
> +-------------------------------+
> |  200  |   30  |    0  |   97  | (src)
> +-------------------------------+
> |  192  |  168  |    0  |  180  | (dest)
> +-------------------------------+
> ip_input: p->len 153 p->tot_len 153
> udp_input: received datagram of length 133
> UDP header:
> +-------------------------------+
> |        53     |      4096     | (src port, dest port)
> +-------------------------------+
> |       133     |     0xbb0a    | (len, chksum)
> +-------------------------------+
> udp (192.168.0.180, 4096) <-- (200.30.0.97, 53)
> pcb (0.0.0.0, 4096) --- (200.30.0.97, 53)
> udp_input: calculating checksum
> inet_chksum_pseudo(): checksumming pbuf 20009c14 (has next 0)
> inet_chksum_pseudo(): pbuf chain lwip_chksum()=ffff
> dns_recv: "time.nist.gov": response = 192.43.244.18
> Found ip of host time.nist.gov = 192.43.244.18
> 
> 
> 
> Any idea ? Could by ARP related?
> 
> Thanks,
> Sergio
> 
> 
> 
> 
> 
> 
> 
> 
> On Mon, Jan 19, 2009 at 5:04 PM, Jonathan Larmour <address@hidden> wrote:
>> Rejean Groleau wrote:
>>> Hi Sergio,
>>>
>>> I had the same problem a while back. My problem was two-fold:
>>>
>>> First, I did not have enough pbufs (PBUF_POOL_SIZE and MEMP_NUM_PBUF)
>>> to do everything I was doing at startup. Once I got the LWIP_DEBUGF
>>> and LWIP_PLATFORM_DIAG macros properly implemented, I was able to see
>>> the errors coming from the dns_send() function.
>> That should have timed out eventually though, right? Just checking there
>> isn't a real bug in the lwIP DNS code here - it shoudl be able to cope with
>> running out of pbufs.
>>
>>> Then, I was not waiting for the interface to be up and initialized before
>>> calling dns_gethostbyname(). This was solved by calling netif_is_up().
>> Again, did it time out eventually? Or it should have worked shortly after
>> the interface was up, even if that wasn't straight away.
>>
>> Jifl
>> --
>> eCosCentric Limited      http://www.eCosCentric.com/     The eCos experts
>> Barnwell House, Barnwell Drive, Cambridge, UK.       Tel: +44 1223 245571
>> Registered in England and Wales: Reg No 4422071.
>> ------["Si fractum non sit, noli id reficere"]------       Opinions==mine
>>
>>
>> _______________________________________________
>> lwip-users mailing list
>> address@hidden
>> http://lists.nongnu.org/mailman/listinfo/lwip-users
> 
> 
> _______________________________________________
> lwip-users mailing list
> address@hidden
> http://lists.nongnu.org/mailman/listinfo/lwip-users


-- 
eCosCentric Limited      http://www.eCosCentric.com/     The eCos experts
Barnwell House, Barnwell Drive, Cambridge, UK.       Tel: +44 1223 245571
Registered in England and Wales: Reg No 4422071.
------["Si fractum non sit, noli id reficere"]------       Opinions==mine