When you wget the file, can you check if its sha256sum matches what's in /mnt/sysimage/var/cache/yum/anaconda*/primary.xml.gz for that package?  If that's fine, then we can proceed with trying to figure out what crazy networking problem is going on here.

Hmm, there's only "sha1sum" command available.. no sha256sum?

Also there's no primary.xml.gz in /mnt/sysimage/var/cache/yum/anaconda*/ directory.

There's a75e0184a58b95011684ff760bce2d1c868b054fc8eb17d04276611bc58aecd0-primary.sqlite though..

How do I verify the checksum?

Ok, I used scp to transfer the wget'ed iputils rpm, and /mnt/sysimage/var/cache/yum/anaconda*/ contents to a normal linux box.

I then used "sqlite3 a75e0184a58b95011684ff760bce2d1c868b054fc8eb17d04276611bc58aecd0-primary.sqlite
 .dump > dump.txt" command and got the sha256sum extracted, it's: 86befd5f8432b88461dccf936fcebd7adc6b5b62b2f1a941487141e23d5c7b7f

And then:

$ sha256sum iputils-20071127-10.fc13.x86_64.rpm
86befd5f8432b88461dccf936fcebd7adc6b5b62b2f1a941487141e23d5c7b7f  iputils-20071127-10.fc13.x86_64.rpm

So the checksum seems to match..

After some investigation it looks like a problem in anaconda in whatever fetches the RPM files from the FTP server..

During F13 installer if I do CTRL-ALT-F2 and use wget I can perfectly fine fetch the iputils rpm, every time. 

Also if I run "python" and "import urlgrabber; urlgrabber.urlgrab('ftp://ftp.funet.fi/pub/mirrors/fedora.redhat.com/pub/fedora/linux/releases/13/Fedora/x86_64/os/Packages/iputils-20071127-10.fc13.x86_64.rpm');"

That works fine too. Every time.

I captured the FTP sessions from both anaconda (or whatever it uses), and from my manual wget+urlgrabber sessions and the difference seems to be anaconda uses FTP "REST 1384" command before starting the transfer for every RPM file..  while my manual wget+urlgrabber tests don't use that.

I guess that "REST 1384" makes it to skip the rpm header? or something? Why otherwise it would "re-start the transfer at offset 1384" ? When it's actually downloading the files for the first time..

Maybe the FTP server in question (ftp.funet.fi, which runs pureftpd) has some problem/bug with that REST feature? 

From the wiresharp logs I can also see that anaconda starts to fetch the iputils rpm (after executing that REST 1384), data transfer happens for a small amount of time, and then it's just silence.. and around 55 seconds later the anaconda client gets logged out from the server and the filetransfer fails.

I also just verified this issue is NOT caused by NAT router. I tested with direct public ip (without any firewalls), and F13 installer failed in the same way.

The header end location should change from pkg to pkg. If anaconda is keeping one of them around that might explain the corruption.

Is there a way for me to replicate the exact FTP client functionality that anaconda uses? (or whatever tools/libs anaconda calls to do that). Using some python script or so..

Someone familiar with anaconda please let me know where to look for the FTP handling code..

I just verified the bug on a different computer, which uses also different internet connection.

I used the same FTP mirror.

So, if someone has tips how to figure out the exact ftp client functionality that anaconda uses, I'd like to debug this further and get the ftp client fixed..

anaconda uses yum which uses python-urlgrabber which uses curl.

I'd guess the problem is in curl, or if that works then in python-urlgrabber (command = urlgrabber).

Try out this code, please

import yum

my = yum.YumBase()
my.setCacheDir()
len(my.pkgSack)
r = my.repos.findRepos('fedora')[0]
p = r.sack.returnPackages()[0]

print 'Retrieving %s from %s' % (p, r.id)
r.getPackage(p)
print p.localPkg()

It seems I can't run that code from the CTRL-ALT-F2 console from the installer.
"/etc/yum.conf" is not there, required by len(my.pkgSack). If I touch the file, then findRepos() fails because there are no repositories set up.

I tried running that python code from already installed F13 box. I modified yum.repos.d and configured/enabled only ftp.funet.fi mirror. Python code works OK there, no problems downloading the files using FTP.

I compared the wireshark captures, and the only difference I can see is the fact that during F13 installation I see those "REST 1384" FTP commands issued.. 

Wireshark capture from that python code (from a normal installed F13 box) doesn't show the REST commands.. so they are only used/enabled by the installer, somehow..

so the question is what causes those "REST 1384" commands when anaconda is running? Remember running "wget" from the installer is fine, it doesn't use those REST commands and it works ok.

Any ideas how to troubleshoot this further?

I downloaded http://urlgrabber.baseurl.org/download/urlgrabber-3.9.1.tar.gz and grepped around..

byterange.py:

class ftpwrapper(urllib.ftpwrapper):
    # range support note:
    # this ftpwrapper code is copied directly from
    # urllib. The only enhancement is to add the rest
    # argument and pass it on to ftp.ntransfercmd
    def retrfile(self, file, type, rest=None):

..
..
          # Try to retrieve as a file
            try:
                cmd = 'RETR ' + file
                conn = self.ftp.ntransfercmd(cmd, rest)
            except ftplib.error_perm, reason:
                if str(reason)[:3] == '501':
                    # workaround for REST not supported error
                    fp, retrlen = self.retrfile(file, type)
                    fp = RangeableFileObject(fp, (rest,''))
                    return (fp, retrlen)
                elif str(reason)[:3] != '550':
                    raise IOError, ('ftp error', reason), sys.exc_info()[2]


So urlgrabber definitely has some FTP REST magic.. I'll investigate further.

Pasi, I think you'll find that the above code is never called on F-13+ urlgrabber.

Here's a wireshark capture (as text) for a failing anaconda f13 installer session, for port 21 FTP traffic:
http://pasik.reaktio.net/fedora/f13-install-port21.thark

(Wireshark capture was taken from a Linux NAT-router/firewall routing the traffic for the f13 box).

192.168.0.100 is the F13 anaconda installer.
193.166.3.2 is ftp.funet.fi fedora FTP mirror.

so first it tries to fetch:
- updates.img
- product.img
- install.img
- .treeinfo
- repomd.xml
- a75e0184a58b95011684ff760bce2d1c868b054fc8eb17d04276611bc58aecd0-primary.sqlite.bz2
- fce31f091be8211a394d8942fcf4f6cbeffa3d40d87b61af55a97b1a88b46987-Fedora-13-comps.xml
- 2afec9b506dd4f46bd68d674d579a6fdff4f0618c78f86c48301fca5e660130e-Fedora-13-comps.xml.gz
- 5c3ab96a2b58cb1b6ca21d59539e294bb9a95c8fdbb8ab209429e98bd2cc0853-filelists.sqlite.bz2

And after those some actual rpms:

- cronie-anacron-1.4.4-1.fc13.x86_64.rpm
- rsyslog-4.4.2-6.fc13.x86_64.rpm
- iputils-20071127-10.fc13.x86_64.rpm

and the installation fails on iputils-20071127-10.fc13.x86_64.rpm, because the FTP client gets disconnected after some 60 seconds delay from the FTP server. Anaconda installer also shows iputils rpm failure on the GUI error message.

As you can see, anaconda/yum/urlgrabber/curl definitely uses FTP "REST 1384" command on the rpms! 


464.040445 192.168.0.100 -> 193.166.3.2  FTP Request: MDTM iputils-20071127-10.fc13.x86_64.rpm
464.065068  193.166.3.2 -> 192.168.0.100 FTP Response: 213 20100305092306
464.065232 192.168.0.100 -> 193.166.3.2  FTP Request: PASV
464.070863  193.166.3.2 -> 192.168.0.100 FTP Response: 227 Entering Passive Mode (193,166,3,2,136,219)
464.076726 192.168.0.100 -> 193.166.3.2  FTP Request: SIZE iputils-20071127-10.fc13.x86_64.rpm
464.082340  193.166.3.2 -> 192.168.0.100 FTP Response: 213 121012
464.082494 192.168.0.100 -> 193.166.3.2  FTP Request: REST 1384
464.088031  193.166.3.2 -> 192.168.0.100 FTP Response: 350 Restarting at 1384
464.088181 192.168.0.100 -> 193.166.3.2  FTP Request: RETR iputils-20071127-10.fc13.x86_64.rpm
464.093774  193.166.3.2 -> 192.168.0.100 FTP Response: 150-Accepted data connection
464.133559 192.168.0.100 -> 193.166.3.2  TCP 58992 > ftp [ACK] Seq=2155 Ack=6575 Win=9856 Len=0 TSV=338092 TSER=770052855
524.089983 192.168.0.100 -> 193.166.3.2  TCP 58992 > ftp [FIN, ACK] Seq=2155 Ack=6575 Win=9856 Len=0 TSV=398047 TSER=770052855
524.095679  193.166.3.2 -> 192.168.0.100 TCP ftp > 58992 [ACK] Seq=6575 Ack=2156 Win=49232 Len=0 TSV=770058855 TSER=398047
524.095928  193.166.3.2 -> 192.168.0.100 FTP Response: 150 Logout.

From the urlgrabber sources I can see the FTP REST stuff mentioned on the urlgrabber byterange code..

To me it looks like either the server or the client has some problems with that REST stuff. I have no idea what makes urlgrabber use that method..

I haven't had time to investigate more yet..

Also note (from the full capture log) that it issues the same "REST 1384" FTP command for *all* the rpm files! I have no idea why..

okay I think I know what's going on here.

anaconda downloads the pkg hdrs to check its transaction before downloading the rest of the pkg.

anaconda is just using urlgrabber to do this but for some reason it seems to be thinking that the byte offset for all of the rpms beyond their header is the same, which is.... unlikely.

ftp REST 1384 means - start reading from byte 1384

I'll look around some more to see if I can figure out where 1384 is coming from

Thanks for looking at it. Did you find anything?

Any updates? Do you want me to test something?

My bug sounds similar enough to this that I'll jump in...

Anaconda v13.21.56 (RHEL6 beta2) doesn't seem to like HTTP servers which don't support byte ranges. For example, python's own SimpleHTTPServer, when run like this:

$ python -m SimpleHTTPServer 8989

as a target for the anaconda url, works fine up to the point where the first RPM is requested:

GET /Packages/iputils-20071127-12.el6.s390x.rpm HTTP/1.1
Range: bytes=1384-18407
User-Agent: Red Hat Enterprise Linux (anaconda)/6.0
Host: <my.ip.address>
Accept: */*

at which point I see exactly the behaviour described in this bug ("rpm cannot be opened... missing file ... corrupt package". Note the popular "1384" offset again...

In /tmp/anaconda.log we get:
17:10:38,642 WARNING : Try 1/10 for http://<my.ip.address>/Packages/iputils-20071127-12.el6.s390x.rpm failed: [Errno 14] Downloaded more than max size for http://<my.ip.address>/Packages/iputils-20071127-12.el6.s390x.rpm: 19124 > 17024
17:10:38,911 WARNING : Failed to get http://<my.ip.address>/Packages/iputils-20071127-12.el6.s390x.rpm from mirror 1/1, or downloaded file is corrupt


I know that SimpleHTTPServer doesn't support Range: requests
# Python SimpleHTTPServer
curl --silent --range 0-499 http://localhost:8989/Packages/iputils-20071127-12.el6.s390x.rpm | wc --bytes
122184

compared to
# Apache httpd 2.2.3
curl --silent --range 0-499 http://localhost:8001/Packages/iputils-20071127-12.el6.s390x.rpm | wc --bytes
500


This all sounds very similar to bug 140387.

Thanks for jumping in! Good to hear I'm not the only one seeing this behaviour :)

This looks like a urlgrabber bug/feature. There's no obvious indication to the caller that the data returned is not what was requested, using byte ranges with a non-byte-range-supporting http server.

Within the debug shell of a running install:
>>> urlgrabber.urlread('http://' + apacheserver + '/EULA', range=[0,34])
'END USER LICENSE AGREEMENT\nRED HAT'

works fine, but

>>> urlgrabber.urlread('http://' + pythonserver + '/EULA', range=[0,34])
'END USER LICENSE AGREEMENT\nRED HAT\xc2\xae ENTERPRISE LINUX\xc2\xae AND RED HAT APPLICATIONS\n\n\nThis end user license agreement ...'
[snip]

continues to read the whole file. This is unsafe; the caller cannot tell that it receives bad data.

BTW, 1384 is the simply the header start offset for 99% of RHEL6 packages. No magic (or bugs) around this value; I expect it's similar for recent Fedora releases as well (see repodata/*primary.xml.gz).

There's a comment in bug 140387 about this being handled (at least for FTP URLs) in urlgrabber CVS:

http://yum.baseurl.org/gitweb?p=urlgrabber.git;a=commit;h=bbe5dac3c4037e87bd8e51066e7cf44b5f0f4411

There doesn't appear to be any code in that commit to handle HTTP. I might mention this on the yum-devel list and see if anyone bites (bytes, haha).

Pasi, what happens if you try the urlgrabber.urlread() fragment above against your suspect pureftpd FTP server?

James, why is the FTP REST workaround fragment never called on F13+ urlgrabber? Is there a different way that byte ranges are supposed to be handled?

> James, why is the FTP REST workaround fragment never called on F13+ urlgrabber?
> Is there a different way that byte ranges are supposed to be handled?

 From this commit onwards:

http://yum.baseurl.org/gitweb?p=urlgrabber.git;a=commitdiff;h=79e1c58d08df12d8e31898e56c24ec38bb9ef71c

...urlgrabber isn't doing any of the ByteRange stuff internally, AFAIK. The pycurl based urlgrabber went into Fedora in F-13.
 But it looks like we either need to fix curl, or add some code back into urlgrabber that fakes ByteRanges when they aren't supported.

Philip: Bingo. I just tried that.

- Start F13 URL installation using ftp://ftp.funet.fi mirror
- Wait for the installer to fail download iputils rpm
- Go to CTRL-ALT-F2
- Execute:

python
import urlgrabber
urlgrabber.urlread('ftp://ftp.funet.fi/pub/mirrors/fedora.redhat.com/pub/fedora/linux/releases/13/Fedora/x86_64/os/Packages/iputils-20071127-10.fc13.x86_64.rpm', range=[0,34])

Running that command makes it wait for around 1 minute and then it gives an error:
urlgrabber.grabber.URLGrabError: [Errno 12] Timeout on : (28, '')

Which is *exactly* the same error I see during F13 Anaconda installer when using ftp.funet.fi mirror!!

I also tried:
urlgrabber.urlread('ftp://ftp.funet.fi/pub/mirrors/fedora.redhat.com/pub/fedora/linux/releases/13/Fedora/x86_64/os/Packages/iputils-20071127-10.fc13.x86_64.rpm', range=[1384,1600])

And it gives the same error.

Btw that ftp.funet.fi mirror is public, so everyone can try those commands, and hopefully reproduce the problem :)

And hey, ftp.funet.fi is the original home of Linux, so we need to get this stuff working ;)

Ok, I just confirmed it doesn't have to be F13 installer anaconda session to reproduce this!

It also fails on a normal (installed) F13 box, like this:


[root@f13 ~]# python
Python 2.6.4 (r264:75706, Jun  4 2010, 18:20:31) 
[GCC 4.4.4 20100503 (Red Hat 4.4.4-2)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import urlgrabber
>>> urlgrabber.urlread('ftp://ftp.funet.fi/pub/mirrors/fedora.redhat.com/pub/fedora/linux/releases/13/Fedora/x86_64/os/Packages/iputils-20071127-10.fc13.x86_64.rpm',
... range=[0,34])
Traceback (most recent call last):
  File "<stdin>", line 2, in <module>
  File "/usr/lib/python2.6/site-packages/urlgrabber/grabber.py", line 638, in urlread
    return default_grabber.urlread(url, limit, **kwargs)
  File "/usr/lib/python2.6/site-packages/urlgrabber/grabber.py", line 1019, in urlread
    s = self._retry(opts, retryfunc, url, limit)
  File "/usr/lib/python2.6/site-packages/urlgrabber/grabber.py", line 886, in _retry
    r = apply(func, (opts,) + args, {})
  File "/usr/lib/python2.6/site-packages/urlgrabber/grabber.py", line 998, in retryfunc
    fo = PyCurlFileObject(url, filename=None, opts=opts)
  File "/usr/lib/python2.6/site-packages/urlgrabber/grabber.py", line 1063, in __init__
    self._do_open()
  File "/usr/lib/python2.6/site-packages/urlgrabber/grabber.py", line 1351, in _do_open
    self._do_grab()
  File "/usr/lib/python2.6/site-packages/urlgrabber/grabber.py", line 1481, in _do_grab
    self._do_perform()
  File "/usr/lib/python2.6/site-packages/urlgrabber/grabber.py", line 1281, in _do_perform
    raise err
urlgrabber.grabber.URLGrabError: [Errno 12] Timeout on : (28, '')
>>> 


So now it should be very easy for others to reproduce this!
Note that wget, curl, lftp, firefox, and every other tool that I tried works OK for that url! I've only seen the problem with urlgrabber.

See:

[root@f13 ~]# curl -o /dev/null ftp://ftp.funet.fi/pub/mirrors/fedora.redhat.com/pub/fedora/linux/releases/13/Fedora/x86_64/os/Packages/iputils-20071127-10.fc13.x86_64.rpm
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  118k  100  118k    0     0  59613      0  0:00:02  0:00:02 --:--:-- 59818


[root@f13 ~]# wget -O /dev/null ftp://ftp.funet.fi/pub/mirrors/fedora.redhat.com/pub/fedora/linux/releases/13/Fedora/x86_64/os/Packages/iputils-20071127-10.fc13.x86_64.rpm
--2010-09-19 16:42:22--  ftp://ftp.funet.fi/pub/mirrors/fedora.redhat.com/pub/fedora/linux/releases/13/Fedora/x86_64/os/Packages/iputils-20071127-10.fc13.x86_64.rpm
           => “/dev/null”
Resolving ftp.funet.fi... 193.166.3.2, 2001:708:10:9::20:2
Connecting to ftp.funet.fi|193.166.3.2|:21... connected.
Logging in as anonymous ... Logged in!
==> SYST ... done.    ==> PWD ... done.
==> TYPE I ... done.  ==> CWD (1) /pub/mirrors/fedora.redhat.com/pub/fedora/linux/releases/13/Fedora/x86_64/os/Packages ... done.
==> SIZE iputils-20071127-10.fc13.x86_64.rpm ... 121012
==> PASV ... done.    ==> RETR iputils-20071127-10.fc13.x86_64.rpm ... done.

    [    <=>                                                                                         ] 121,012     86.8K/s   in 1.4s    

2010-09-19 16:42:24 (86.8 KB/s) - “/dev/null” saved [121012]

Any chances for a fix before F14 goes GA ?

The bug/problem is very easy to reproduce with the steps described above.. maybe I should try patching the problem myself.. :)

Not likely. It's not a blocker for f14 and it is not likely to impact a lot of people.

Ok. I'm now able to reproduce this bug with just 'curl':

[root@f13 ~]# curl -o foo.test --range 1384-1400 ftp://ftp.funet.fi/pub/mirrors/fedora.redhat.com/pub/fedora/linux/releases/13/Fedora/x86_64/os/Packages/iputils-20071127-10.fc13.x86_64.rpm
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100    17    0    17    0     0      0      0 --:--:--  0:01:00 --:--:--     0
curl: (28) FTP response timeout


Removing the "--range" option makes it work OK.

So it's definitely a bug in curl. Urlgrabber uses PyCurl, which uses curl.

I opened a bug against curl: https://bugzilla.redhat.com/show_bug.cgi?id=643656

This bug has now been fixed in curl.

I've tried Fedora 14 anaconda with fixed curl, and the ftp.funet.fi problem is solved.

Note the default Fedora 14 anaconda installer still has old/buggy curl.

This message is a reminder that Fedora 13 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 13.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '13'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 13's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 13 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Fedora 13 changed to end-of-life (EOL) status on 2011-06-25. Fedora 13 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.