RobertCNelson / linux-dev

MIT License
150 stars 96 forks source link

dev-mmcblkxxx takes too long to mount #45

Closed mariobrizuela closed 7 years ago

mariobrizuela commented 7 years ago

Hello,

I hope this is the right place to post this issue. I´ve been fighting to reduce the boot time on several Debian images and I´ve been hiting two big obstacles in the process. "Networking.service" is the biggest time consumer during boot up, followed by "dev-mmcblk1p1.device", this last one is the mounting process of the SD card? How can I reduce this times? This happens with the internal emmc as well and with most 4.4.xx kernels.

root@beaglebone:/etc/modules-load.d# cat /etc/dogtag BeagleBoard.org Debian Image 2017-09-01 root@beaglebone:/etc/modules-load.d# uname -r 4.4.84-ti-r120 root@beaglebone:/etc/modules-load.d# systemd-analyze blame 1min 33.080s networking.service 57.921s dev-mmcblk1p1.device 7.059s generic-board-startup.service 3.054s loadcpufreq.service 2.544s systemd-logind.service 2.229s systemd-udev-trigger.service 1.882s udhcpd.service 1.869s bb-wl18xx-wlan0.service 1.647s rsyslog.service 1.563s pppd-dns.service 1.150s systemd-user-sessions.service 1.129s systemd-journald.service 1.075s rc-local.service 1.012s hostapd.service 998ms dnsmasq.service 565ms cpufrequtils.service 549ms systemd-tmpfiles-setup-dev.service 484ms capemgr.service 421ms systemd-modules-load.service 368ms sys-kernel-debug.mount 358ms dev-mqueue.mount 347ms systemd-udevd.service 342ms systemd-remount-fs.service 311ms kmod-static-nodes.service 287ms sys-fs-fuse-connections.mount 276ms systemd-timesyncd.service 261ms sys-kernel-config.mount 235ms mnt-ramdisk.mount 220ms systemd-update-utmp.service 206ms systemd-journal-flush.service 198ms var-log.mount 189ms bb-wl18xx-bluetooth.service 187ms systemd-tmpfiles-setup.service 179ms systemd-random-seed.service 173ms systemd-update-utmp-runlevel.service 94ms systemd-sysctl.service root@beaglebone:/etc/modules-load.d#

RobertCNelson commented 7 years ago

Jessie or Stretch?

in Stretch with v4.9.x:

debian@test-bbb-2:~$ uname -r
4.9.50-ti-r62
debian@test-bbb-2:~$ systemd-analyze blame
         42.447s generic-board-startup.service
         38.501s networking.service
         15.914s dev-mmcblk0p1.device
         14.857s apt-daily.service
         11.997s apt-daily-upgrade.service
          4.656s mnt-farm.mount
          4.293s exim4.service
          3.769s capemgr.service
          3.748s systemd-logind.service
          3.703s rsyslog.service
          3.396s ssh.service
          2.856s avahi-daemon.service
          2.153s systemd-udev-trigger.service
          1.226s loadcpufreq.service
           670ms systemd-journald.service
           635ms rpc-statd.service
           590ms rpc-statd-notify.service
           519ms systemd-timesyncd.service
           469ms systemd-tmpfiles-setup-dev.service
           420ms systemd-random-seed.service
           414ms systemd-udevd.service
           406ms sys-kernel-debug.mount
           396ms systemd-modules-load.service
           376ms systemd-remount-fs.service
           350ms systemd-journal-flush.service
           323ms rc-local.service
           319ms rpcbind.service
           305ms run-rpc_pipefs.mount
           289ms sys-fs-fuse-connections.mount
           285ms kmod-static-nodes.service
           264ms systemd-update-utmp.service
           261ms cpufrequtils.service
           224ms sys-kernel-config.mount
           212ms systemd-tmpfiles-setup.service
           198ms systemd-sysctl.service
           147ms systemd-user-sessions.service
           127ms systemd-update-utmp-runlevel.service
            94ms systemd-tmpfiles-clean.service
            90ms dev-mqueue.mount
            58ms nfs-config.service
mariobrizuela commented 7 years ago

This is Jessie from "bone-debian-8.9-iot-armhf-2017-09-01-4gb".

mariobrizuela commented 7 years ago

I downloaded the latest Stretch lxqt version and update the kernel. I disabled "generic-board-startup.service" because it added more than 1 minute to the boot process. Here the results.

debian@beaglebone:/opt/scripts/tools/eMMC$ uname -r 4.9.52-ti-r64 debian@beaglebone:/opt/scripts/tools/eMMC$ systemd-analyze blame 35.710s dev-mmcblk0p1.device 6.762s apache2.service 5.683s lightdm.service 3.974s loadcpufreq.service 3.311s systemd-logind.service 3.205s systemd-udev-trigger.service 2.785s cpufrequtils.service 2.301s networking.service 2.133s udhcpd.service 1.556s connman.service 1.463s bb-wl18xx-wlan0.service 1.318s avahi-daemon.service 1.297s ti-ipc-dra7xx.service 1.279s udisks2.service 1.220s ssh.service 1.095s systemd-journald.service 863ms user@1000.service 833ms systemd-udevd.service 780ms polkit.service 690ms capemgr.service 657ms systemd-timesyncd.service 648ms rsyslog.service 552ms wpa_supplicant.service 406ms systemd-random-seed.service 377ms systemd-user-sessions.service 349ms dev-mqueue.mount 334ms kmod-static-nodes.service 327ms hostapd.service 325ms systemd-modules-load.service 319ms systemd-journal-flush.service 319ms sys-fs-fuse-connections.mount 306ms systemd-tmpfiles-setup-dev.service 305ms systemd-tmpfiles-setup.service 288ms systemd-update-utmp.service 279ms cloud9.service 269ms systemd-remount-fs.service 254ms bb-wl18xx-bluetooth.service 240ms systemd-sysctl.service 237ms sys-kernel-config.mount 224ms systemd-update-utmp-runlevel.service 205ms sys-kernel-debug.mount

Also cape slots are gone.

debian@beaglebone:/opt/scripts/tools/eMMC$ sudo cat /sys/devices/platform/bone_capemgr/slots
cat: /sys/devices/platform/bone_capemgr/slots: No such file or directory

debian@beaglebone:/opt/scripts/tools/eMMC$ sudo apt-get install bb-cape-overlays Reading package lists... Done Building dependency tree
Reading state information... Done bb-cape-overlays is already the newest version (4.4.20170929.0-0rcnee1~stretch+20170929). 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.

RobertCNelson commented 7 years ago

on the very first startup, generic-board-startup.service takes about a minute, as it takes about that long to generate your host ssh key's for the first time..

On the second reboot, it's just slow as it's setting up the usb interface thru libcomposite, and it's got a few wait states while loading the usb modules..

Correct, "slots" file is gone, as U-Boot is in control:

https://elinux.org/Beagleboard:BeagleBoneBlack_Debian#U-Boot_Overlays

Regards,

mariobrizuela commented 7 years ago

Actually, I have enabled uboot overlays in uEnv.txt with "enable_uboot_overlays=1". The way to get the slots back was to upgrade the kernel with v4.9.x mainline. It was v4.9.x-ti the kernel with missing slots.

sudo ./update_kernel.sh --lts-4_9 --bone-channel

RobertCNelson commented 7 years ago

No, i need to patch "--lts-4_9 --bone-channel" and have it disable the slots file too...

When using "enable_uboot_overlays=1" i'm disabling the "slots" file, as users are still using it when u-boot overlays are active. You can't do kernel and u-boot overlays at the same time.

Regards,

RobertCNelson commented 7 years ago

The "only" way forward to have the slots file available, is to "disable" u-boot overlays.

Then you'll get the slots file back, BUT you will be on your own.. Kernel Overlays is a dead end, it's not going to be maintained, and i'll be killing it completely in the next few releases..

Regards,

RobertCNelson commented 7 years ago

Here is the transition plan:

https://elinux.org/Beagleboard:BeagleBoneBlack_Debian#Where_did_the_slots_file_go.3F

Regards,

mariobrizuela commented 7 years ago

Thank you Robert for the explanation about UBoot overlays. Regarding the original post, is there any way to reduce this time? -> "35.710s dev-mmcblk0p1.device"

Regards

RobertCNelson commented 7 years ago

With Debian Jessie (bone-debian-8.9-iot-armhf-2017-09-01-4gb.img.xz)

dogtag:[BeagleBoard.org Debian Image 2017-09-01]
4.4.84-ti-r120

1st boot:

root@beaglebone:~# systemd-analyze blame | grep generic
         58.528s generic-board-startup.service

root@beaglebone:~# systemd-analyze blame | grep mmc
         37.686s dev-mmcblk0p1.device

2nd boot:

root@beaglebone:~# systemd-analyze blame | grep generic
         33.765s generic-board-startup.service

root@beaglebone:~# systemd-analyze blame | grep mmc
         33.032s dev-mmcblk0p1.device
RobertCNelson commented 7 years ago

With the same Jessie image, but upgraded kernel:

root@beaglebone:~# uname -r ; systemd-analyze blame | grep mmc
4.9.52-ti-r64
         31.563s dev-mmcblk0p1.device

root@beaglebone:~# uname -r ; systemd-analyze blame | grep mmc
4.14.0-rc3-bone2
         21.979s dev-mmcblk0p1.device
RobertCNelson commented 7 years ago

and now with stretch:

Debian Stretch: [BeagleBoard.org Debian Image 2017-10-01]
4.4.89-ti-r130

1st boot:

root@beaglebone:~# systemd-analyze blame | grep generic
         43.402s generic-board-startup.service
root@beaglebone:~# systemd-analyze blame | grep mmc
         30.888s dev-mmcblk0p1.device

2nd boot:

root@beaglebone:~# systemd-analyze blame | grep generic
         31.759s generic-board-startup.service
root@beaglebone:~# systemd-analyze blame | grep mmc
         30.096s dev-mmcblk0p1.device

4.9.x: (4.9.52-ti-r64)

root@beaglebone:~# systemd-analyze blame | grep generic
         29.145s generic-board-startup.service
root@beaglebone:~# systemd-analyze blame | grep mmc
         17.955s dev-mmcblk0p1.device

4.14.x: (4.14.0-rc3-bone2)

root@beaglebone:~# systemd-analyze blame | grep generic
         24.035s generic-board-startup.service
root@beaglebone:~# systemd-analyze blame | grep mmc
         13.449s dev-mmcblk0p1.device

So, Stretch is faster then Jessie. v4.9.x-ti works faster in Stretch, while v4.14.x beats them all (one thing i've done differently in v4.14.x, i've nuked the raid6/btrfs, as it wasted a good minute of bootup times, and really no ones uses it..)

Regards,

mariobrizuela commented 7 years ago

Great improvement Robert. How can I upgrade from 4.9.x to 4.14.x ? That "4.14.0-rc3-bone2" is not in the LATEST-ti repo but in the LATEST-omap-psp.

RobertCNelson commented 7 years ago

Via:

cd /opt/scripts/tools/
git pull
sudo ./update_kernel.sh --bone-kernel --lts-4_14

Regards,