[U-Boot] u-boot tftp problem

[U-Boot] u-boot tftp problem

[PF4Public]

Hi all

I'm asking for your help to figure out what interferes with u-boot's tftp in my setup.
I have a custom board with TI OMAP SoC. I'm trying to download uImage from linux machine 
via tftp. It fails with timeouts (most of the tries timeout limit exceeds) on several, but 
succeeds on others. However any other combination not involving u-boot is flawless. Even 
when the board in question has booted kernel. Comparing network settings (incl. sysctl) 
gave no significant difference between serving machines, which run Linux.
Following tests were taken:
u-boot <-> i686-pae Linux
u-boot <-> i686-pae Linux kvm guest
u-boot <-> x86_64 windows 7
Results are as follows:

1. u-boot <-> i686-pae Linux
Using DaVinci-EMAC device
TFTP from server 192.168.100.254; our IP address is 192.168.100.88
Filename 'uImage'.
Load address: 0xc0700000
Loading: ############T ###############################T ##########T ############
          #######T ################################################T ##########
          ##########################T #######################################
          ###########################T ######################################
          ################################T #################################
#################################################################
          ########T #########################################################
          ##################
          11.7 KiB/s
done
Bytes transferred = 2418464 (24e720 hex)
Corresponding traffic dump can be found here:
http://pastebin.com/hBBwe9bL

2. u-boot <-> i686-pae Linux kvm guest
Using DaVinci-EMAC device
TFTP from server 192.168.100.112; our IP address is 192.168.100.88
Filename 'uImage'.
Load address: 0xc0700000
Loading: #################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
#################################################################
          ##################
          795.9 KiB/s
done
Bytes transferred = 2418464 (24e720 hex)
Corresponding traffic dump can be found here:
http://pastebin.com/ZXYdpmSe

3. u-boot <-> x86_64 windows 7
Using DaVinci-EMAC device
TFTP from server 192.168.100.86; our IP address is 192.168.100.88
Filename 'uImage'.
Load address: 0xc0700000
Loading: #################################################################
#################################################################
          ###################################
          173.8 KiB/s
done
Bytes transferred = 2418464 (24e720 hex)
Corresponding traffic dump can be found here:
http://pastebin.com/UWFEZjTz

At this point I have no idea, what could cause timeouts for u-boot and I have no more 
clues on how to solve this. Any help greatly appreciated.

Thanks in advance
Best regards

[U-Boot] u-boot tftp problem

[Joe Hershberger]

On Fri, Feb 13, 2015 at 8:05 PM, PF4Public <PF4Public@mail.ru> wrote:
>
> Hi all
>
> I'm asking for your help to figure out what interferes with u-boot's tftp
in my setup.
> I have a custom board with TI OMAP SoC. I'm trying to download uImage
from linux machine via tftp. It fails with timeouts (most of the tries
timeout limit exceeds) on several, but succeeds on others. However any
other combination not involving u-boot is flawless. Even when the board in
question has booted kernel. Comparing network settings (incl. sysctl) gave
no significant difference between serving machines, which run Linux.

Are you saying that it is completely consistent that when TFTPing from a
specific TFTP server to u-boot you always get these time-outs, but with a
different one you never get them? Have you compared the traffic on the
wire? Try turning on debug traces in the network stack and compare what it
sees to what's on the wire. Perhaps the davinci emac driver is causing you
trouble. Is there a cache enabled on your board that you could disable to
eliminate the driver's tolerance of a cache?

> Following tests were taken:
> u-boot <-> i686-pae Linux
> u-boot <-> i686-pae Linux kvm guest
> u-boot <-> x86_64 windows 7
> Results are as follows:
>
> 1. u-boot <-> i686-pae Linux
> Using DaVinci-EMAC device
> TFTP from server 192.168.100.254; our IP address is 192.168.100.88
> Filename 'uImage'.
> Load address: 0xc0700000
> Loading: ############T ###############################T ##########T
############
>          #######T ################################################T
##########
>          ##########################T
#######################################
>          ###########################T
######################################
>          ################################T
#################################
> #################################################################
>          ########T
#########################################################
>          ##################
>          11.7 KiB/s
> done
> Bytes transferred = 2418464 (24e720 hex)
> Corresponding traffic dump can be found here:
> http://pastebin.com/hBBwe9bL
>
> 2. u-boot <-> i686-pae Linux kvm guest
> Using DaVinci-EMAC device
> TFTP from server 192.168.100.112; our IP address is 192.168.100.88
> Filename 'uImage'.
> Load address: 0xc0700000
> Loading: #################################################################
> #################################################################
> #################################################################
> #################################################################
> #################################################################
> #################################################################
> #################################################################
>          ##################
>          795.9 KiB/s
> done
> Bytes transferred = 2418464 (24e720 hex)
> Corresponding traffic dump can be found here:
> http://pastebin.com/ZXYdpmSe
>
> 3. u-boot <-> x86_64 windows 7
> Using DaVinci-EMAC device
> TFTP from server 192.168.100.86; our IP address is 192.168.100.88
> Filename 'uImage'.
> Load address: 0xc0700000
> Loading: #################################################################
> #################################################################
>          ###################################
>          173.8 KiB/s
> done
> Bytes transferred = 2418464 (24e720 hex)
> Corresponding traffic dump can be found here:
> http://pastebin.com/UWFEZjTz
>
> At this point I have no idea, what could cause timeouts for u-boot and I
have no more clues on how to solve this. Any help greatly appreciated.

Simply that the packet that the network stack expects has not be received
at that level. They could be lost in a number of places.

> Thanks in advance
> Best regards
> _______________________________________________
> U-Boot mailing list
> U-Boot at lists.denx.de
> http://lists.denx.de/mailman/listinfo/u-boot

[U-Boot] u-boot tftp problem

[PF4Public]

 >Are you saying that it is completely consistent that when TFTPing from a specific TFTP 
server to u-boot you always get these time-outs, but with a different one you never get them?
Exactly. Even when I try to download uImage from kvm host machine, I still got timeouts. 
But should I try to download from kvm guest, which obviously uses the same switch port as 
does host, I got fast download. A little slower, but still without timeouts, tftp gets 
uImage from MS Windows 7 host, which runs http://tftpd32.jounin.net/ .That was the first I 
could google up for Windows.

 >Have you compared the traffic on the wire?
Careful examination of dumps leads me to the following conclusions:
1. Download session with timeouts had a lot of retransmissions. Having those dumps made on 
server side, I'm not certain if U-Boot really received lost packets, but what is clear is 
that tftpd sends some packets twice before receiving acknowledgement packet from U-Boot.
2. Even though Windows server uses block sizes 1500, still those packets are perfectly 
delivered to U-Boot.
3. Sometimes something really weird happens, like this:
00:00:00.000061 IP (tos 0x0, ttl 64, id 34608, offset 0, flags [DF], proto UDP (17), 
length 544)

     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 423

00:00:00.000417 IP (tos 0x0, ttl 255, id 11691, offset 0, flags [DF], proto UDP (17), 
length 32)

     192.168.100.88.3821 > 192.168.100.254.56334:  4 ACK block 423

00:00:00.000056 IP (tos 0x0, ttl 64, id 34609, offset 0, flags [DF], proto UDP (17), 
length 544)

     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 424

00:00:05.000165 IP (tos 0x0, ttl 255, id 11692, offset 0, flags [DF], proto UDP (17), 
length 32)

     192.168.100.88.3821 > 192.168.100.254.56334:  4 ACK block 423

00:00:00.000014 IP (tos 0x0, ttl 64, id 34720, offset 0, flags [DF], proto UDP (17), 
length 544)

     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 424

00:00:00.000015 IP (tos 0x0, ttl 64, id 34721, offset 0, flags [DF], proto UDP (17), 
length 544)

     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 424

00:00:00.000521 IP (tos 0x0, ttl 255, id 11693, offset 0, flags [DF], proto UDP (17), 
length 32)

     192.168.100.88.3821 > 192.168.100.254.56334:  4 ACK block 424

That is tftpd sends block 423 and receives acknowledgement. Then it sends block 424, but 
the reply was delayed for 5 seconds and was in fact for block 423 again.
This happened quite often with timing variations:
     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 526
     192.168.100.88.3821 > 192.168.100.254.56334:  4 ACK block 526
     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 527
     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 527
     192.168.100.88.3821 > 192.168.100.254.56334:  4 ACK block 526
     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 527
     192.168.100.88.3821 > 192.168.100.254.56334:  4 ACK block 527
...
     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 1558
     192.168.100.88.3821 > 192.168.100.254.56334:  4 ACK block 1558
     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 1559
     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 1559
     192.168.100.88.3821 > 192.168.100.254.56334:  4 ACK block 1558
     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 1559
     192.168.100.88.3821 > 192.168.100.254.56334:  4 ACK block 1559

 >Try turning on debug traces in the network stack and compare what it sees to what's on 
the wire.
I'll give it a try, thanks.
Is "#define DEBUG_NET_PKT 0" related here, which I found in include/net.h ?

 >Perhaps the davinci emac driver is causing you trouble. Is there a cache enabled on your 
board that you could disable to eliminate the driver's tolerance of a cache?
You mean "CONFIG_SYS_ICACHE_OFF" and "CONFIG_SYS_DCACHE_OFF". I'll try them. I've googled 
something like "dcache off" command, but it didn't work for me in U-Boot command line, so 
suppose I should disable them via defines. Am I right?

 >Simply that the packet that the network stack expects has not be received at that level. 
They could be lost in a number of places.
But how come they are lost so selectively? I mean that somehow packets from Windows and 
other Linux hosts got delivered just fine.

Best regards.

[U-Boot] u-boot tftp problem

[Nikolay Dimitrov]

Hi,

Here's what I think happens:

When working with large TFTP packets (probably 4096 bytes, as set in
your board config file), U-Boot TFTP code sends wrong acknowledges for
the TFTP packets. If the TFTP server implementation is too strict (the
OpenBSD server is a good example), the transfer will inevitably fail
very soon after start. Here's an example:

1. TFTP server sends block 0
2. Board acknowledges block 0
3. TFTP server sends block 1
4. Board acknowledges block 0

At this point you can see either proper or very obscure error messages
in the TFTP server logs, so trust only to network dumps for diagnostics.

What can you do to resolve your issue:

1. Fix the bug in U-Boot tftp networking code and submit a patch.
2. Reduce your TFTP blksize, by commenting CONFIG_TFTPBLOCKSIZE  in
your board config. The default value is 1468, which should work fine.
U-Boot behaves nicer with smaller packets.

Hope this helps. Regards,
Nikolay

[U-Boot] Fwd: Re: u-boot tftp problem

[PF4Public]

 >When working with large TFTP packets (probably 4096 bytes, as set in your board config 
file), U-Boot TFTP code sends wrong acknowledges for the TFTP packets.

But what is clear from traffic dumps is that a packet size never exceeds 516 when 
downloading from Linux machine's tftpd. Am I missing something here?

 >Reduce your TFTP blksize, by commenting CONFIG_TFTPBLOCKSIZE in your board config. The 
default value is 1468, which should work fine.

I have tried reducing tftpblocksize with editenv command of U-Boot, that ensured reduced 
blocksizes, which was clearly visible in tcpdump, but sadly it didn't change a thing.
Btw I cannot find CONFIG_TFTPBLOCKSIZE in the whole source tree of U-Boot: "grep -r 
CONFIG_TFTPBLOCKSIZE ." and "grep -r TFTPBLOCKSIZE ." gave no output.

Best regards

[U-Boot] u-boot tftp problem

[Nikolay Dimitrov]

Hi PF4Public,

On 02/20/2015 04:43 PM, PF4Public wrote:
>  >When working with large TFTP packets (probably 4096 bytes, as set in
> your board config file), U-Boot TFTP code sends wrong acknowledges for
> the TFTP packets.
>
> But what is clear from traffic dumps is that a packet size never exceeds
> 516 when downloading from Linux machine's tftpd. Am I missing something
> here?

Hmm. Please check your boards' initial TFTP request packet, and
especially the "option blksize" field. My understanding is that it
should be the same as the size of all incoming TFTP data blocks, and
when they're not equal sized, U-Boot TFTP code has issues to reassemble
the fragments. That's why I recommended to use the default max TFTP
blocksize which is 1468 bytes and fits nicely in a single ethernet
frame.

This is based on my own observations some time ago when debugged
somewhat similar issues with U-Boot running on ARM, and trying to boot
from OpenBSD TFTP server.

>  >Reduce your TFTP blksize, by commenting CONFIG_TFTPBLOCKSIZE in your
> board config. The default value is 1468, which should work fine.
>
> I have tried reducing tftpblocksize with editenv command of U-Boot, that
> ensured reduced blocksizes, which was clearly visible in tcpdump, but
> sadly it didn't change a thing.
> Btw I cannot find CONFIG_TFTPBLOCKSIZE in the whole source tree of
> U-Boot: "grep -r CONFIG_TFTPBLOCKSIZE ." and "grep -r TFTPBLOCKSIZE ."
> gave no output.

Sorry for the confusion, it's CONFIG_TFTP_BLOCKSIZE.

Regards,
Nikolay

[U-Boot] u-boot tftp problem

[PF4Public]

Hello, Nikolay

Now I see, what you mean.

 From every dump the requests made by U-Boot are the same. They're as follows:
00:00:00.000310 IP (tos 0x0, ttl 255, id 11267, offset 0, flags [DF], proto UDP (17), 
length 66)
     192.168.100.88.3821 > 192.168.100.254.69:  38 RRQ "uImage" octet timeout 5 blksize 1468

However the answers from servers are different.
Linux host answers with 516 byte packets for example:
00:00:00.004169 IP (tos 0x0, ttl 64, id 29290, offset 0, flags [DF], proto UDP (17), 
length 544)
     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 1
Whereas Windows host answers conforming to requested block size somewhat:
00:00:00.000136 IP (tos 0x0, ttl 128, id 20143, offset 0, flags [none], proto UDP (17), 
length 1500)
     192.168.100.86.63959 > 192.168.100.88.3811:  1472 DATA block 1

Also those configs, which contain "#define CONFIG_TFTP_BLOCKSIZE 4096", are from 
completely different boards. As well as neither did I nor it was by default defined for 
mine board.
So I believe that there must be something different with my set up. I have not yet tried 
debugging network at U-Boot side, but it is the last thing, that left to check.

But anyway thank you for your insight for large packets and U-Boot.

Best regards

[U-Boot] u-boot tftp problem

[Joe Hershberger]

On Fri, Feb 20, 2015 at 10:51 AM, PF4Public <PF4Public@mail.ru> wrote:
>
> Hello, Nikolay
>
> Now I see, what you mean.
>
> From every dump the requests made by U-Boot are the same. They're as
follows:
> 00:00:00.000310 IP (tos 0x0, ttl 255, id 11267, offset 0, flags [DF],
proto UDP (17), length 66)
>     192.168.100.88.3821 > 192.168.100.254.69:  38 RRQ "uImage" octet
timeout 5 blksize 1468
>
> However the answers from servers are different.
> Linux host answers with 516 byte packets for example:
> 00:00:00.004169 IP (tos 0x0, ttl 64, id 29290, offset 0, flags [DF],
proto UDP (17), length 544)
>     192.168.100.254.56334 > 192.168.100.88.3821:  516 DATA block 1
> Whereas Windows host answers conforming to requested block size somewhat:
> 00:00:00.000136 IP (tos 0x0, ttl 128, id 20143, offset 0, flags [none],
proto UDP (17), length 1500)
>     192.168.100.86.63959 > 192.168.100.88.3811:  1472 DATA block 1
>
> Also those configs, which contain "#define CONFIG_TFTP_BLOCKSIZE 4096",
are from completely different boards. As well as neither did I nor it was
by default defined for mine board.
> So I believe that there must be something different with my set up. I
have not yet tried debugging network at U-Boot side, but it is the last
thing, that left to check.

I actually just tested this on sandbox against atftpd server 0.7 in Ubuntu
Linux.  Even with IP Fragmentation and 4k block size, u-boot acked every
packet correctly.

Can you provide more exact details on the servers you are trying including
versions?  Perhaps also provide pcap files (not text dumps) so the exact
packet contents can be observed?

-Joe

[U-Boot] u-boot tftp problem

[PF4Public]

Hello, Joe

 >Can you provide more exact details on the servers you are trying including versions?
 >Perhaps also provide pcap files (not text dumps) so the exact packet contents can be 
observed?

Recently I've done some tests, hope you find them interesting.

Server in question:
Linux sterver 3.2.0-4-686-pae #1 SMP Debian 3.2.65-1+deb7u1 i686 GNU/Linux
  r8169 0000:08:04.0: eth1: RTL8169sc/8110sc at 0xf827e000, 90:e6:ba:07:3e:a5, XID 
18000000 IRQ 19
ii  tftpd                             0.17-18 i386                  Trivial file transfer 
protocol server

I have mirrored 2 ports at the switch. Here's what I have found:
1. tftp block ack packets have some extra bytes. They are "mage octet tim". Suppose that's 
because buffer reuse in u-boot after "uImage octet timeout 5", although I'm not so sure.
2. u-boot never generates wrong block acks if "#define TIMEOUT     8000UL". Obviously 8 
seconds is enough for tftp server to resend the block, so with this define, it is not 
timing out and keeps downloading till the end. Ofcourse it just masks the real problem, 
nothing more.
3. at the times of server resending block it is u-boot who lost the packet. I believe that 
if the packet was delivered to mirrored port, it must have been delivered to u-boot. But 
logging at u-boot shows no evidence of packet reception, however packets following missed 
one are registered.
4. the only condition at which u-boot didn't loose packets and downloaded uImage without 
timeouts was when I made it log everything regarding network. this gave enormous output to 
console, but no tftp packets lost. Even though I tested it twice it could be a coincidence.

Also I tried disabling caches. Rebuilding with "CONFIG_SYS_ICACHE_OFF" and 
"CONFIG_SYS_DCACHE_OFF" was no difference at all. At least for tftp download.

I was about to provide you with pcap files from mirror port and corresponding u-boot 
console log, but sadly seems that I have deleted u-boot log by mistake :( I think I have 
to repeat the whole thing before I can provide you with them both.

Best regards

[U-Boot] u-boot tftp problem

[PF4Public]

Hello, Joe

Recently I have repeated my tests.
U-Boot logs along with pcap dump could be found here: 
https://mega.co.nz/#!g4UnVaDL!K6ej1OQXg5VE6pU5cmFoELkeqasIDXH1OZbDwdLiXSU

I may be wrong, but after careful examination of these dumps (and older ones), I came to 
the following conclusion:
Somehow lost packets coincide with "--- NetLoop timeout handler set" and "--- NetLoop 
timeout".
Which is supported by these facts: a) both server and u-boot tftp timeouts are equal to 5 
sec; b) whenever I define "#define TIMEOUT     8000UL", even if U-Boot fails to catch the 
first packet, it catches the second one and does not reset it's timer (which seems to 
generate another one ACK for the last received block upon reset); c) similarly if I set 
"tftptimeout 1000", U-Boot still catches the second packet if it could not catch the first 
one. Moreover after yet another examination of windows server session dump I find, this is 
exactly what happens with windows server, which ignores u-boot's request for 5 second 
timeout and resends blocks after 1 second, which are perfectly captured by U-Boot; d) all 
those packets within 5 seconds' timeout got caught by U-Boot.
Please correct me if I'm wrong.
And if I'm not - is there anything to mitigate this, other than "set tftptimeout 1000" and 
"put switch inbetween"? Referring someone at ti.com to this thread maybe?

BTW: putting switch inbetween makes it easier for U-Boot to catch up with tftp server.
Compare:
U-Boot > dhcp
BOOTP broadcast 1
DHCP client bound to address 192.168.100.88 (81 ms)
Using DaVinci-EMAC device
TFTP from server 192.168.100.254; our IP address is 192.168.100.88
Filename 'uImage'.
Load address: 0xc0700000
Loading: ##T T ##T ##
Abort
U-Boot > dhcp
BOOTP broadcast 1
BOOTP broadcast 2
BOOTP broadcast 3
DHCP client bound to address 192.168.100.88 (1074 ms)
Using DaVinci-EMAC device
TFTP from server 192.168.100.254; our IP address is 192.168.100.88
Filename 'uImage'.
Load address: 0xc0700000
Loading: #T #T ####T ##T #T T #T #T #T ##T #T ###
Abort
U-Boot > dhcp
BOOTP broadcast 1
BOOTP broadcast 2
BOOTP broadcast 3
BOOTP broadcast 4
BOOTP broadcast 5
DHCP client bound to address 192.168.100.88 (4817 ms)
Using DaVinci-EMAC device
TFTP from server 192.168.100.254; our IP address is 192.168.100.88
Filename 'uImage'.
Load address: 0xc0700000
Loading: #################################################################
#################################################################
#################################################################
          ####T ##########################################T ###################
#################################################################
#################################################################
          #############################################T
          34.2 KiB/s
done
Bytes transferred = 2225360 (21f4d0 hex)
U-Boot > dhcp
BOOTP broadcast 1
BOOTP broadcast 2
BOOTP broadcast 3
DHCP client bound to address 192.168.100.88 (1079 ms)
Using DaVinci-EMAC device
TFTP from server 192.168.100.254; our IP address is 192.168.100.88
Filename 'uImage'.
Load address: 0xc0700000
Loading: ################################################T #######T ##########
          ####################T ###############T ####################T ###########
#################################################################
#################################################################
          ####################################################T #############
#################################################################
          #############################################T
          32.2 KiB/s
done
Bytes transferred = 2225360 (21f4d0 hex)


Best regards