Need advice on how to reduce boot time

[mikero...@hotmail.com]

My application uses a beaglebone black rev C. The application is written in python and uses serial ports, Adafruit_BBIO.PWM and GPIO and is started by systemctl as a service. There is no graphical interface, just an LCD controlled with GPIO. It takes 90 seconds after boot up before the program sounds the 'greeting' with PWM. I need to reduce this to <10 seconds. I had high hopes for an older 2Gb image, but I think it predated the universal cape and I was having trouble getting it to work. There is also an IOT image, but some gpio's didn't work. After update_kernal.sh the gpio's worked and I'm on 4.14.108. I'm not sure this is even the IOT image anymore. I've tried various tweaks I've found on the web without much success. Can I make a standard image work and if so how? Must I create my own image? Where do I start? Thank you, Mike.

[TJF]

On

4.14.146-bone29

I've a system starting my custom application after 7 s. The entire boot process ends after 18 s, WiFi network connection included.

It's a standard image, but no cape-universal overlays ==> no Adafruit libraries, instead libpruio.

[Dennis Lee Bieber]

On Sun, 23 Feb 2020 14:07:27 -0800 (PST), in
gmane.comp.hardware.beagleboard.user

While it won't catch pre-kernel activity, have you checked the dmesg
list for what may be taking a long time in the start up sequence.

debian@beaglebone:~$ dmesg
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.14.108-ti-r113
(root@x1-am57xx-beagle-x15-2gb) (gcc version 6.3.0 20170516 (Debian
6.3.0-18+deb9u1)) #1 SMP PREEMPT Wed Jul 31 00:01:10 UTC 2019
[ 0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7),
cr=10c5387d

<SNIP>

[ 1.403928] of_cfs_init
[ 1.404112] of_cfs_init: OK
[ 1.405499] ALSA device list:
[ 1.405510] No soundcards found.
[ 1.412495] Freeing unused kernel memory: 1024K
[ 23.407696] EXT4-fs (mmcblk0p1): mounted filesystem with ordered data
mode. Opts: (null)
[ 24.075336] systemd[1]: System time before build time, advancing clock.

<SNIP>

Some 20+ seconds seem to have been lost in mounting the uSD file system

[ 24.172908] ip_tables: (C) 2000-2006 Netfilter Core Team

<SNIP>

[ 25.507732] pru-rproc 4a338000.pru: PRU rproc node
/ocp/pruss_soc_bus@4a326004/pruss@0/pru@38000 probed successfully
[ 26.566698] systemd-journald[1665]: Received request to flush runtime
journal from PID 1
[ 33.501536] nf_conntrack version 0.5.0 (8192 buckets, 32768 max)
[ 33.810548] pvrsrvkm: loading out-of-tree module taints kernel.

<SNIP>

Another 6+ seconds going from the flush to nf_conntrack


<SNIP.

[ 38.310254] IPv6: ADDRCONF(NETDEV_UP): usb0: link is not ready
[ 38.365824] IPv6: ADDRCONF(NETDEV_CHANGE): usb0: link becomes ready
[ 38.718825] IPv6: ADDRCONF(NETDEV_UP): usb1: link is not ready
debian@beaglebone:~$

And 39 seconds, it is all ready. That is on an IoT image.



--
Dennis L Bieber

[mikero...@hotmail.com]

My r127 seems very different from your r113!  Would mounting the EXT4-fs set the lower limit on what I can hope for?  I also have a major jump at 45s to 95s.

Mike

...

[    1.385532] ALSA device list:

[    1.385540]   No soundcards found.

[    1.392228] Freeing unused kernel memory: 1024K

[    1.847501] random: systemd-udevd: uninitialized urandom read (16 bytes read)

[    1.848225] random: systemd-udevd: uninitialized urandom read (16 bytes read)

[    1.848327] random: systemd-udevd: uninitialized urandom read (16 bytes read)

[   30.019624] EXT4-fs (mmcblk1p1): mounted filesystem with ordered data mode. Opts: (null)

[   30.463662] systemd[1]: System time before build time, advancing clock.

[   30.534304] ip_tables: (C) 2000-2006 Netfilter Core Team

[   30.568706] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)

[   30.569470] systemd[1]: Detected architecture arm.

[   30.575682] systemd[1]: Set hostname to <beaglebone>.

[   31.174199] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.

[   31.175075] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.

[   31.175446] systemd[1]: Listening on fsck to fsckd communication Socket.

[   31.175897] systemd[1]: Listening on Journal Socket (/dev/log).

[   31.176334] systemd[1]: Listening on udev Control Socket.

[   31.176550] systemd[1]: Reached target Remote File Systems.

[   31.176704] systemd[1]: Reached target Swap.

[   31.615583] EXT4-fs (mmcblk1p1): re-mounted. Opts: errors=remount-ro

[   32.714627] systemd-journald[873]: Received request to flush runtime journal from PID 1

[   34.166674] random: crng init done

[   34.166698] random: 7 urandom warning(s) missed due to ratelimiting

[   39.624602] nf_conntrack version 0.5.0 (8192 buckets, 32768 max)

[   41.169342] using random self ethernet address

[   41.169362] using random host ethernet address

[   41.238422] net eth0: initializing cpsw version 1.12 (0)

[   41.315227] SMSC LAN8710/LAN8720 4a101000.mdio:00: attached PHY driver [SMSC LAN8710/LAN8720] (mii_bus:phy_addr=4a101000.mdio:00, irq=POLL)

[   41.344681] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready

[   42.089601] Mass Storage Function, version: 2009/09/11

[   42.089624] LUN: removable file: (no medium)

[   42.723517] using random self ethernet address

[   42.723537] using random host ethernet address

[   43.094457] usb0: HOST MAC 74:e1:82:62:fc:20

[   43.098695] usb0: MAC 74:e1:82:62:fc:21

[   43.117882] usb1: HOST MAC 74:e1:82:62:fc:23

[   43.118204] usb1: MAC 74:e1:82:62:fc:24

[   43.359164] cpsw 4a100000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx

[   43.359253] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready

[   43.509508] configfs-gadget gadget: high-speed config #1: c

[   43.735440] 8021q: 802.1Q VLAN Support v1.8

[   43.736197] 8021q: adding VLAN 0 to HW filter on device eth0

[   44.594345] IPv6: ADDRCONF(NETDEV_UP): usb1: link is not ready

[   95.541078] pvrsrvkm: loading out-of-tree module taints kernel.

[   95.572136] pruss 4a300000.pruss: creating PRU cores and other child platform devices

[   95.603724] remoteproc remoteproc1: 4a334000.pru is available

[   95.603854] pru-rproc 4a334000.pru: PRU rproc node /ocp/pruss_soc_bus@4a326004/pruss@0/pru@34000 probed successfully

[   95.617530] remoteproc remoteproc2: 4a338000.pru is available

[   95.617648] pru-rproc 4a338000.pru: PRU rproc node /ocp/pruss_soc_bus@4a326004/pruss@0/pru@38000 probed successfully

[   95.717866] [drm:drm_minor_register]

[   95.717885] [drm:drm_minor_register]

[   95.718403] [drm:drm_minor_register] new minor registered 128

[   95.718415] [drm:drm_minor_register]

[   95.724539] [drm:drm_minor_register] new minor registered 1

[   95.730470] [drm] Initialized pvr 1.14.3699939 20110701 for 56000000.sgx on minor 1

On Monday, February 24, 2020 at 11:46:53 AM UTC-5, Dennis Bieber wrote:

On Sun, 23 Feb 2020 14:07:27 -0800 (PST), in
gmane.comp.hardware.beagleboard.user

[Robert Nelson]

On Mon, Feb 24, 2020 at 6:35 PM <mikero...@hotmail.com> wrote:
>
> My r127 seems very different from your r113! Would mounting the EXT4-fs set the lower limit on what I can hope for? I also have a major jump at 45s to 95s.
>
> Mike
> ...
> [ 1.385532] ALSA device list:
> [ 1.385540] No soundcards found.
> [ 1.392228] Freeing unused kernel memory: 1024K
> [ 1.847501] random: systemd-udevd: uninitialized urandom read (16 bytes read)
> [ 1.848225] random: systemd-udevd: uninitialized urandom read (16 bytes read)
> [ 1.848327] random: systemd-udevd: uninitialized urandom read (16 bytes read)

> [ 34.166674] random: crng init done

> [ 34.166698] random: 7 urandom warning(s) missed due to ratelimiting

In /boot/uEnv.txt at the end of the "cmdline" add:

rng_core.default_quality=100

it was added by default around ~6 months ago, so your image is just old. ;)

Regards,

--
Robert Nelson
https://rcn-ee.com/

[mikero...@hotmail.com]

Thanks!  That cut almost 10s from the boot time.  Do you see any other improvements that can be made to the uEnv.txt?  It's original except for enabling the UARTs and the rng_core addition. 

#Docs: http://elinux.org/Beagleboard:U-boot_partitioning_layout_2.0

uname_r=4.14.108-ti-r127

#uuid=

#dtb=

###U-Boot Overlays###

###Documentation: http://elinux.org/Beagleboard:BeagleBoneBlack_Debian#U-Boot_Overlays

###Master Enable

enable_uboot_overlays=1

###

###Overide capes with eeprom

#uboot_overlay_addr0=/lib/firmware/<file0>.dtbo

#uboot_overlay_addr1=/lib/firmware/<file1>.dtbo

#uboot_overlay_addr2=/lib/firmware/<file2>.dtbo

#uboot_overlay_addr3=/lib/firmware/<file3>.dtbo

###

###Additional custom capes

#uboot_overlay_addr4=/lib/firmware/<file4>.dtbo

#uboot_overlay_addr5=/lib/firmware/<file5>.dtbo

#uboot_overlay_addr6=/lib/firmware/<file6>.dtbo

#uboot_overlay_addr7=/lib/firmware/<file7>.dtbo

###

###Custom Cape

#dtb_overlay=/lib/firmware/<file8>.dtbo

###

###Disable auto loading of virtual capes (emmc/video/wireless/adc)

#disable_uboot_overlay_emmc=1

disable_uboot_overlay_video=1

disable_uboot_overlay_audio=1

disable_uboot_overlay_wireless=1

disable_uboot_overlay_adc=1

###

###PRUSS OPTIONS

###pru_rproc (4.4.x-ti kernel)

#uboot_overlay_pru=/lib/firmware/AM335X-PRU-RPROC-4-4-TI-00A0.dtbo

###pru_rproc (4.14.x-ti kernel)

uboot_overlay_pru=/lib/firmware/AM335X-PRU-RPROC-4-14-TI-00A0.dtbo

###pru_uio (4.4.x-ti, 4.14.x-ti & mainline/bone kernel)

#uboot_overlay_pru=/lib/firmware/AM335X-PRU-UIO-00A0.dtbo

optargs=quiet drm.debug=7 capemgr.enable_partno=BB-UART1,BB-UART2,BB-UART4

###

###Cape Universal Enable

enable_uboot_cape_universal=1

###

###Debug: disable uboot autoload of Cape

#disable_uboot_overlay_addr0=1

#disable_uboot_overlay_addr1=1

#disable_uboot_overlay_addr2=1

#disable_uboot_overlay_addr3=1

###

###U-Boot fdt tweaks... (60000 = 384KB)

#uboot_fdt_buffer=0x60000

###U-Boot Overlays###

cmdline=coherent_pool=1M net.ifnames=0 quiet rng_core.default_quality=100

#In the event of edid real failures, uncomment this next line:

#cmdline=coherent_pool=1M net.ifnames=0 quiet video=HDMI-A-1:1024x768@60e

#Use an overlayfs on top of a read-only root filesystem:

#cmdline=coherent_pool=1M net.ifnames=0 quiet overlayroot=tmpfs

##enable Generic eMMC Flasher:

#cmdline=init=/opt/scripts/tools/eMMC/init-eMMC-flasher-v3.sh

[mikero...@hotmail.com]

Maybe the IOT image isn't helping.  Is this the best place to get images? https://beagleboard.org/latest-images  They are all dated 8/2019.

Mike

[Hans Leeuw (Electrumpet)]

These maybe?

https://elinux.org/Beagleboard:BeagleBoneBlack_Debian#Debian_Stretch_Console_Snapshot

Hans.

--
For more options, visit http://beagleboard.org/discuss
---
You received this message because you are subscribed to the Google Groups "BeagleBoard" group.
To unsubscribe from this group and stop receiving emails from it, send an email to beagleboard...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/beagleboard/5150d67f-8a69-4f1f-bd1c-79bc55f7bfd9%40googlegroups.com.

[TJF]

In the past three years I learned: the newer the image, the longer the boot time.

Developers are working in the wrong direction. They're wasting their time. They're wasting my time, since I've to spend more and more effort to strip the boot process to the bare minimum.

[Robert Nelson]

On Thu, Feb 27, 2020 at 9:04 AM TJF <jeli.f...@gmail.com> wrote:
>
> In the past three years I learned: the newer the image, the longer the boot time.
>
> Developers are working in the wrong direction. They're wasting their time. They're wasting my time, since I've to spend more and more effort to strip the boot process to the bare minimum.

We have Developers?

I assume you've been testing and providing feedback on:

https://elinux.org/Beagleboard:BeagleBoneBlack_Debian#Debian_Buster_Console_Snapshot

[TJF]

Am Donnerstag, 27. Februar 2020 16:14:08 UTC+1 schrieb RobertCNelson:

On Thu, Feb 27, 2020 at 9:04 AM TJF <jeli.f...@gmail.com> wrote:
>
> In the past three years I learned: the newer the image, the longer the boot time.
>
> Developers are working in the wrong direction. They're wasting their time. They're wasting my time, since I've to spend more and more effort to strip the boot process to the bare minimum.

We have Developers?

;-)

I assume you've been testing and providing feedback on:

https://elinux.org/Beagleboard:BeagleBoneBlack_Debian#Debian_Buster_Console_Snapshot

Not yet. My latest test is the above mentioned 4.14.146-bone29 kernel.

Regards,

--
Robert Nelson
https://rcn-ee.com/

I cannot spend often ten days making a new image usable.

Regards

PS: Is it possible to make the bone flavor images quick boot?

[Robert Nelson]

This should help that: First boot is still nasty.. (did i miss any
am5 bloat on am3 devices?)

https://github.com/RobertCNelson/boot-scripts/blob/master/boot/am335x_evm.sh#L869-L911

This situation is still killing us:

[ 3.491157] [drm] Cannot find any crtc or sizes
[ 13.026157] EXT4-fs (mmcblk0p1): mounted filesystem with ordered
data mode. Opts: (null)

Why does it take 10+ seconds to mount the drive.. I've been wondering
are we doing something wrong?

[mikero...@hotmail.com]

4.19.94-ti-34 gives me: Startup finished in 17.090s (kernel) + 33.884s (userspace) = 50.974s

Should I try 4.14.146-bone29? If so where can I find it?

Mike

[Robert Nelson]

On Fri, Feb 28, 2020 at 5:20 PM <mikero...@hotmail.com> wrote:
>
>
> 4.19.94-ti-34 gives me: Startup finished in 17.090s (kernel) + 33.884s (userspace) = 50.974s
>
> Should I try 4.14.146-bone29? If so where can I find it?

sudo /opt/scripts/tools/update_kernel.sh --kernel 4.14.146-bone29

[mikero...@hotmail.com]

Great!  I thought I would have to put it on an sd card.

The 4.14 series does seem to work better for me than the 4.19.  I'm at about 40s before my app starts.  Still not happy, but half as unhappy as I was.  Everyone on this site has been a great help.

[Hans Leeuw]

Hi all,

I am following this discussion with great interest. I am using the PocketBeagle on a musical instrument and it should not take too long to start it up or I miss that all important firsts note!! I am using a PocketBeagle with Linux beaglebone 4.14.108-ti-r127 #1 SMP PREEMPT Wed Jan 29 04:10:14 UTC 2020 armv7l GNU/Linux. I used the console image from elinux.org.

I see a few big gaps in the start up as well. Apart from the filesystem mount which takes a long time (in my case 16+ seconds), there is also a huge gap before the PRU comes online (a gap of 28 seconds!!!). I am suspecting the Edimax USB Wifi driver since I see the same even larger gap on my other (standard) image around the startup of that device. Is this normal, is this something to report or does anyone know a solution or direction in which to look?

dmesg

......

[    1.438453] usb 2-1: new high-speed USB device number 2 using musb-hdrc

[    1.586756] usb 2-1: New USB device found, idVendor=1a40, idProduct=0101

[    1.586773] usb 2-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0

[    1.586781] usb 2-1: Product: USB 2.0 Hub

[    1.587979] hub 2-1:1.0: USB hub found

[    1.588121] hub 2-1:1.0: 4 ports detected

[    1.590052] PM: bootloader does not support rtc-only!

[   18.885434] EXT4-fs (mmcblk0p1): mounted filesystem with ordered data mode. Opts: (null)

[   19.524350] systemd[1]: System time before build time, advancing clock.

[   19.629059] ip_tables: (C) 2000-2006 Netfilter Core Team

[   19.670063] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)

[   19.671004] systemd[1]: Detected architecture arm.

[   19.673162] systemd[1]: Set hostname to <beaglebone>.

[   20.251318] systemd[1]: Listening on fsck to fsckd communication Socket.

[   20.252772] systemd[1]: Listening on Journal Audit Socket.

[   20.253398] systemd[1]: Started Forward Password Requests to Wall Directory Watch.

[   20.253851] systemd[1]: Listening on udev Control Socket.

[   20.255661] systemd[1]: Created slice System Slice.

[   20.260328] systemd[1]: Mounting /sys/kernel/debug...

[   20.262000] systemd[1]: Created slice system-getty.slice.

[   21.187890] EXT4-fs (mmcblk0p1): re-mounted. Opts: errors=remount-ro

[   21.782096] systemd-journald[1387]: Received request to flush runtime journal from PID 1

[   25.913687] nf_conntrack version 0.5.0 (8192 buckets, 32768 max)

[   27.173192] using random self ethernet address

[   27.173212] using random host ethernet address

[   27.387371] using random self ethernet address

[   27.387390] using random host ethernet address

[   27.491447] usb0: HOST MAC 5a:4e:7b:a0:01:c1

[   27.495152] usb0: MAC 52:08:20:37:1b:cf

[   27.502656] usb1: HOST MAC 0e:0d:48:41:f9:e3

[   27.502828] usb1: MAC ea:2d:e9:92:95:d8

[   27.823542] IPv6: ADDRCONF(NETDEV_UP): usb0: link is not ready

[   27.928126] IPv6: ADDRCONF(NETDEV_UP): usb1: link is not ready

[   29.902568] usb 1-1: new high-speed USB device number 2 using musb-hdrc

[   30.051126] usb 1-1: New USB device found, idVendor=7392, idProduct=b822

[   30.051147] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[   30.051156] usb 1-1: Product: AC1200 MU-MIMO USB2.0 Adapter

[   30.051164] usb 1-1: Manufacturer: Realtek

[   30.051171] usb 1-1: SerialNumber: 123456

[   58.475688] pruss 4a300000.pruss: creating PRU cores and other child platform devices

[   59.117552] remoteproc remoteproc1: 4a334000.pru is available

[   59.117694] pru-rproc 4a334000.pru: PRU rproc node /ocp/pruss_soc_bus@4a326004/pruss@0/pru@34000 probed successfully

[   59.147747] remoteproc remoteproc2: 4a338000.pru is available

[   59.147890] pru-rproc 4a338000.pru: PRU rproc node /ocp/pruss_soc_bus@4a326004/pruss@0/pru@38000 probed successfully

[   59.868881] 88x2bu: loading out-of-tree module taints kernel.

[   60.536781] RTW: module init start

[   60.536803] RTW: rtl88x2bu v5.3.1_27678.20180430_COEX20180427-5959

[   60.536808] RTW: rtl88x2bu BT-Coex version = COEX20180427-5959

[   60.536887] RTW: rtw_inetaddr_notifier_register

On standard image

[   39.810511] usb 1-1: new high-speed USB device number 2 using musb-hdrc

[   39.979050] usb 1-1: New USB device found, idVendor=7392, idProduct=b822

[   40.010480] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[   40.039314] usb 1-1: Product: AC1200 MU-MIMO USB2.0 Adapter

[   40.066515] usb 1-1: Manufacturer: Realtek

[   40.078152] usb 1-1: SerialNumber: 123456

[   74.239144] [drm] Initialized pvr 1.14.3699939 20110701 for 56000000.sgx on minor 1

[   78.924470] RTW: module init start

[   78.934546] RTW: rtl88x2bu v5.3.1_27678.20180430_COEX20180427-5959

[   78.946541] RTW: rtl88x2bu BT-Coex version = COEX20180427-5959

[   78.960099] RTW: rtw_inetaddr_notifier_register

Best,

Hans Leeuw

[Daniel Kulp]

The first big gap is likely due to an initrd image.   For my apps, we do a "rm -rf /boot/initrd.img*" after creating the image which easily cuts 10 seconds or so off of boot time.

After boot, you can run "systemd-analyze plot > plot.svg" and view the svg to see what's going on.   I definitely found a few of our own scripts were taking a LONG time but splitting them into separate services that can be run in parallel helped a lot.