Re: [lwip-users] lwip reply delayed after long communication idle time

[Jochen Strohbeck]

My http server still suffer from occasional timeouts e.g. when using ping as
shown below.

As already told I am still on 1.4.1 but merged the latest etharp code into
1.4.1 because I still think that the problem is caused by the ARP handling.
If you don't agree let me know.

Let me first show AFAIK a good ping (sorry for posting in German, I hope it
is readable for non-G):

ping -t 192.168.0.100
Antwort von 192.168.0.100: Bytes=32 Zeit=1ms TTL=255
Antwort von 192.168.0.100: Bytes=32 Zeit<1ms TTL=255

    Pakete: Gesendet = 4, Empfangen = 4, Verloren = 0
    (0% Verlust),
Ca. Zeitangaben in Millisek.:
    Minimum = 0ms, Maximum = 1ms, Mittelwert = 0ms

The ping ICMP forces the ARP protocol handler to request the host IP and
then the reply is sent immediately.

432     5188.742678     192.168.0.9     192.168.0.100   ICMP    74      Echo 
(ping) request 
id=0x0001, seq=32/8192, ttl=128 (reply in 435)
433     5188.743381     de:bd:00:00:00:29       Broadcast       ARP     60      
Who has 192.168.0.9? Tell
192.168.0.100
434     5188.743429     Dell_7a:2c:51   de:bd:00:00:00:29       ARP     42      
192.168.0.9 is at
98:e7:43:7a:2c:51
435     5188.743955     192.168.0.100   192.168.0.9     ICMP    74      Echo 
(ping) reply   
id=0x0001, seq=32/8192, ttl=255 (request in 432)


Now in a bad situation (I don't know exactly how to reproduce) the ping
times out first, then delayed replies are reported and after a while
everything seems to work again as usual.

ping -t 192.168.0.100
Zeitüberschreitung der Anforderung.
:
Zeitüberschreitung der Anforderung.
Antwort von 192.168.0.100: Bytes=32 Zeit=475ms TTL=255
Antwort von 192.168.0.100: Bytes=32 Zeit<1ms TTL=255

    Pakete: Gesendet = 15, Empfangen = 7, Verloren = 8
    (53% Verlust),
Ca. Zeitangaben in Millisek.:
    Minimum = 0ms, Maximum = 475ms, Mittelwert = 67ms


Telling from the Wiresharc trace the ping replies are sent but with a delay
of up to 14 seconds. 
It looks to me that the ARP protocol handling is blocked or delayed for
unknown reason.

382     4587.330275     192.168.0.9     192.168.0.100   ICMP    74      Echo 
(ping) request 
id=0x0001, seq=17/4352, ttl=128 (reply in 397)
383     4592.106504     Dell_7a:2c:51   de:bd:00:00:00:29       ARP     42      
Who has
192.168.0.100? Tell 192.168.0.9
:
390     4599.792633     de:bd:00:00:00:29       Broadcast       ARP     60      
Who has 192.168.0.9? Tell
192.168.0.100
:
397     4601.456823     192.168.0.100   192.168.0.9     ICMP    74      Echo 
(ping) reply   
id=0x0001, seq=17/4352, ttl=255 (request in 382)
398     4601.456893     de:bd:00:00:00:29       Dell_7a:2c:51   ARP     64      
192.168.0.100 is at
de:bd:00:00:00:29

Sorry for posting part of the traces in the message body but I don't know
how to explain my observations in a short and more readable way.

Pls find attached the wiresharc trace and LWIP debug printfs.
If I can provide you further information or testing pls let me know.

Thanks,
Jochen

pingprobs.pcap <http://lwip.100.n7.nabble.com/file/t1988/pingprobs.pcap>  
lwip_msg.txt <http://lwip.100.n7.nabble.com/file/t1988/lwip_msg.txt>  
pingoutput.txt <http://lwip.100.n7.nabble.com/file/t1988/pingoutput.txt>  



--
Sent from: http://lwip.100.n7.nabble.com/lwip-users-f3.html