Bug 817301

Summary: Loading of squashfs.img takes very long time.
Product: [Fedora] Fedora Reporter: Jan ONDREJ <ondrejj>
Component: dracutAssignee: dracut-maint
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 17CC: dracut-maint, g.kaviyarasu, harald, jonathan, vanmeeuwen+fedora, wwoods
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-07-03 15:52:42 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Jan ONDREJ 2012-04-28 18:59:59 UTC
Description of problem:
In fedora 16 there was no squashfs.img, vmlinuz+initrd has aprox. same size as squashfs in Fedora 17. Start of Fedora 17 takes aprox. 3 minutes longer due to loading of squashfs.img.

Version-Release number of selected component (if applicable):
Fedora 17 Beta
&
Fedora 17 development (build available today)

How reproducible:
always

Steps to Reproduce:
1. just boot Fedora 17 and see how long fetching squasfs.img
  
Actual results:
Here are part of my logs:

[    8.745599] dracut: fetching http://ftp.upjs.sk/pub/fedora/linux/development/
17/x86_64/os/LiveOS/squashfs.img                                                
http://ftp.upjs.sk/pub/fedora/linux/development/17/x86_64/os/LiveOS/squashfs.img
######################################################################## 100.0% 
udevd[207]: RUN+="socket:..." support will be removed from a future udev release
. Please remove it from: /usr/lib/udev/rules.d/40-multipath.rules:16 and use lib
udev to subscribe to events.                                                    

[  193.042913] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null)                                                                          

Expected results:
Download time aprox. 10-20 seconds.


Additional info:

As you can see, fetching started in 8th second, ended in 193th second, so fetching takes 185 seconds, what is more than 3 minutes.

By downloading same file from same mirror on same machine later, from ALT-F2 console (still not installed, same kernel booted), it takes less:

[anaconda root@(none) /]# wget http://ftp.upjs.sk/pub/fedora/linux/releases/test
/17-Beta/Fedora/x86_64/os/LiveOS/squashfs.img                                   
                                                                                
100%[======================================>] 130,367,488 6.82M/s   in 20s      
                                                                                
2012-04-28 18:47:29 (6.09 MB/s) - `squashfs.img' saved [130367488/130367488]    

So 20 seconds using wget, 3 minutes from boot. Fedora 16 loaded in 10-20 seconds from PXE same size initrd images, so this looks to be a regression.

I also see a very fast move of cursor, when dracut displays download progress. May be problem is, that it is displaying progress too often. By typing ENTER when downloading, it says same percentage on multiple lines, so progress bar is refreshed too often. I am not sure, if this is why download takes 9 times longer.

I can recheck if you update development/17 images.

Comment 1 Jan ONDREJ 2012-05-12 17:42:26 UTC
May be this is a dracut bug. Changing component to dracut.

Comment 2 Harald Hoyer 2012-05-14 12:07:09 UTC
dracut uses "curl"

you can add "rd.debug loglevel=77 log_buf_len=1M" to the kernel command line to see, where curl is executed and ends.

Just attach the dmesg output

Comment 3 Jan ONDREJ 2012-05-14 13:24:43 UTC
With "rd.debug" I can't reproduce this, boot is perfectly fast.

Without any parameter it's 100% reproducible.

Looks like something with curl command output is a problem here.

Comment 4 Will Woods 2012-06-02 18:06:29 UTC
(In reply to comment #0)

> So 20 seconds using wget, 3 minutes from boot. Fedora 16 loaded in 10-20
> seconds from PXE same size initrd images, so this looks to be a regression.

What happens if you use curl to download the image there?
What about curl --progress-bar?

(If curl isn't in the PATH in the anaconda runtime environment, it should be available in /run/initramfs/usr/bin or similar)

Comment 5 Jan ONDREJ 2012-06-03 08:39:05 UTC
(In reply to comment #4)
> What happens if you use curl to download the image there?
> What about curl --progress-bar?

[anaconda root@(none) bin]# time ./curl --progress-bar http://ftp.upjs.sk/pub/fe
dora/linux/releases/17/Fedora/x86_64/os/LiveOS/squashfs.img > /dev/null         
######################################################################## 100.0% 
                                                                                
real    1m57.520s                                                               
user    0m0.732s                                                                
sys     1m47.021s                                                               
[anaconda root@(none) bin]# time ./curl http://ftp.upjs.sk/pub/fedora/linux/rele
ases/17/Fedora/x86_64/os/LiveOS/squashfs.img > /dev/null                        
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current 
                                 Dload  Upload   Total   Spent    Left  Speed   
100  131M  100  131M    0     0  16.8M      0  0:00:07  0:00:07 --:--:-- 16.2M  
                                                                                
real    0m9.341s                                                                
user    0m0.063s                                                                
sys     0m0.694s                                                                
[anaconda root@(none) bin]#                                                     

So aprox. 2 minutes with progress bar, 10 seconds without.

Do we really need this --progress-bar option? For me standard curl output is much nicer, displays download speed, ETA and more information.

With progress bar my cursor is blinking on whole line very fastly. May be curl does not optimize character output and fedoras boot char output is slower like default in real system (not in installer).

I seen two methods of fixing this:

1. rewrite curl --progress-bar option to display progress bar only on change.
2. remove --progress-bar option and leave default download output

Comment 6 Fedora Update System 2012-06-04 14:48:32 UTC
dracut-018-51.git20120604.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/dracut-018-51.git20120604.fc17

Comment 7 Jan ONDREJ 2012-06-04 15:01:43 UTC
(In reply to comment #6)
> dracut-018-51.git20120604.fc17 has been submitted as an update for Fedora 17.
> https://admin.fedoraproject.org/updates/dracut-018-51.git20120604.fc17

Can this fix installer problem? I don't know about any option to install updates to installer.

Comment 8 Fedora Update System 2012-06-05 18:35:33 UTC
dracut-018-52.git20120605.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/dracut-018-52.git20120605.fc17

Comment 9 Jan ONDREJ 2012-06-05 18:40:30 UTC
(In reply to comment #8)
> dracut-018-52.git20120605.fc17 has been submitted as an update for Fedora 17.
> https://admin.fedoraproject.org/updates/dracut-018-52.git20120605.fc17

Please, do not include this bug number in fixed bugs if this will not be really fixed for F17.

If you consider that this can't be fixed in F17, please change component to rawhide.

Comment 10 Fedora Update System 2012-06-05 23:05:39 UTC
Package dracut-018-51.git20120604.fc17:
* should fix your issue,
* was pushed to the Fedora 17 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing dracut-018-51.git20120604.fc17'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-8865/dracut-018-51.git20120604.fc17
then log in and leave karma (feedback).

Comment 11 Fedora Update System 2012-06-11 15:26:40 UTC
dracut-018-55.git20120611.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/dracut-018-55.git20120611.fc17

Comment 12 Harald Hoyer 2012-06-11 15:55:49 UTC
(In reply to comment #9)
> (In reply to comment #8)
> > dracut-018-52.git20120605.fc17 has been submitted as an update for Fedora 17.
> > https://admin.fedoraproject.org/updates/dracut-018-52.git20120605.fc17
> 
> Please, do not include this bug number in fixed bugs if this will not be
> really fixed for F17.
> 
> If you consider that this can't be fixed in F17, please change component to
> rawhide.

it would fix the issue, if you build new installer CDs/DVDs. Please do not block valid updates with your "-1" karma!!!

Comment 13 Fedora Update System 2012-06-18 17:49:06 UTC
dracut-018-65.git20120612.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/FEDORA-2012-9390/dracut-018-65.git20120612.fc17

Comment 14 Fedora Update System 2012-06-22 14:18:06 UTC
dracut-018-78.git20120622.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/dracut-018-78.git20120622.fc17

Comment 15 Fedora Update System 2012-07-03 15:52:42 UTC
dracut-018-78.git20120622.fc17 has been pushed to the Fedora 17 stable repository.  If problems still persist, please make note of it in this bug report.