Very slow first start on Raspberry PI Zero

[dusan-ivanco]

This unofficial amrv6l version (12 and 13) is very slow on rPI0

First start after boot node -e "console.log('Node.js loaded');" takes over 2 min
Official build (11) is ok

[rvagg]

@bnoordhuis any chance you can provide hints for debugging this?

I don't have a zero running at the moment, but on a Pi 1 B+, which isn't too different from a zero:

$ time ./node-v13.11.0-linux-armv6l/bin/node -e "console.log('Node.js loaded');"
Node.js loaded

real	0m1.874s
user	0m1.695s
sys	0m0.139s

So I can't replicate the problem myself.

[dusan-ivanco]

Which hints do you need for debbuging?

I have buildroot and my time is

real 2m9.900s
user 0m1.199s
sys 0m0.153s

now i see, that official build 10 have same problem as your 12 and 13
for me only official build 11 is working as expected

[dusan-ivanco]

BR2_arm=y
BR2_arm1176jzf_s=y
BR2_ARM_EABIHF=y

BR2_PACKAGE_HOST_LINUX_HEADERS_CUSTOM_4_19=y
BR2_TOOLCHAIN_BUILDROOT_CXX=y

BR2_LINUX_KERNEL=y
BR2_LINUX_KERNEL_CUSTOM_TARBALL=y
BR2_LINUX_KERNEL_CUSTOM_TARBALL_LOCATION="$(call github,raspberrypi,linux,64d0a9870ac14d5eb5253f67d984ae348eec1393)/linux-64d0a9870ac14d5eb5253f67d984ae348eec1393.tar.gz"
BR2_LINUX_KERNEL_DEFCONFIG="bcmrpi"
BR2_LINUX_KERNEL_DTS_SUPPORT=y
BR2_LINUX_KERNEL_INTREE_DTS_NAME="bcm2708-rpi-zero-w"
BR2_LINUX_KERNEL_NEEDS_HOST_OPENSSL=y

BR2_PACKAGE_RPI_BT_FIRMWARE=y
BR2_PACKAGE_RPI_FIRMWARE=y
BR2_PACKAGE_RPI_FIRMWARE_X=y
BR2_PACKAGE_RPI_FIRMWARE_INSTALL_DTB_OVERLAYS=y
BR2_PACKAGE_RPI_WIFI_FIRMWARE=y

Required tools to create the SD image

BR2_PACKAGE_HOST_DOSFSTOOLS=y
BR2_PACKAGE_HOST_GENIMAGE=y
BR2_PACKAGE_HOST_MTOOLS=y

Filesystem / image

BR2_TARGET_ROOTFS_EXT2=y
BR2_TARGET_ROOTFS_EXT2_4=y
BR2_TARGET_ROOTFS_EXT2_SIZE="1G"
BR2_TARGET_ROOTFS_TAR=n

BR2_ROOTFS_POST_BUILD_SCRIPT="board/raspberrypi0w/post-build.sh"
BR2_ROOTFS_POST_IMAGE_SCRIPT="board/raspberrypi0w/post-image.sh"
BR2_ROOTFS_POST_SCRIPT_ARGS="--add-miniuart-bt-overlay"

Supervisor Optimization

BR2_CCACHE=y
BR2_CCACHE_DIR="$(TOPDIR)/ccache/rpi0"
BR2_OPTIMIZE_2=y

BR2_TOOLCHAIN_BUILDROOT_GLIBC=y
BR2_PACKAGE_GLIBC_UTILS=y

BR2_TARGET_GENERIC_HOSTNAME="iot"
BR2_TARGET_GENERIC_ISSUE="Welcome to IoT"
BR2_ROOTFS_DEVICE_CREATION_DYNAMIC_EUDEV=y
BR2_ROOTFS_MERGED_USR=y
BR2_TARGET_ENABLE_ROOT_LOGIN=y
BR2_TARGET_GENERIC_ROOT_PASSWD="root"
BR2_SYSTEM_BIN_SH_BASH=y
BR2_ENABLE_LOCALE_PURGE=n
BR2_TARGET_TZ_INFO=y
BR2_TARGET_TZ_ZONELIST="default"
BR2_TARGET_LOCALTIME="Europe/Bratislava"

BR2_LINUX_KERNEL_CUSTOM_LOGO_PATH="$(TOPDIR)/kernel.jpg"
BR2_LINUX_KERNEL_ZIMAGE=y
BR2_LINUX_KERNEL_XZ=y
BR2_PACKAGE_LINUX_TOOLS_GPIO=y

Supervisor Configuration

BR2_PACKAGE_BUSYBOX=y
BR2_PACKAGE_BUSYBOX_SHOW_OTHERS=y
BR2_PACKAGE_BUSYBOX_WATCHDOG=y

BR2_PACKAGE_BASH=y
BR2_PACKAGE_BASH_COMPLETION=y

BR2_PACKAGE_EUDEV=y
BR2_PACKAGE_EUDEV_ENABLE_HWDB=y

BR2_PACKAGE_CRYPTSETUP=y
BR2_PACKAGE_HEIRLOOM_MAILX=y
BR2_PACKAGE_INOTIFY_TOOLS=y
BR2_PACKAGE_MOSQUITTO=y
BR2_PACKAGE_PSPLASH=y
BR2_PACKAGE_SHARED_MIME_INFO=y
BR2_PACKAGE_SWUPDATE=y

BR2_PACKAGE_CA_CERTIFICATES=y
BR2_PACKAGE_OPENSSL=y
BR2_PACKAGE_LIBOPENSSL=y
BR2_PACKAGE_LIBOPENSSL_BIN=y
BR2_PACKAGE_LIBOPENSSL_ENGINES=y

BR2_PACKAGE_BC=y
BR2_PACKAGE_JQ=y
BR2_PACKAGE_MC=y
BR2_PACKAGE_XZ=y

BR2_PACKAGE_DAEMON=y
BR2_PACKAGE_DCRON=y
BR2_PACKAGE_FILE=y
BR2_PACKAGE_FTOP=y
BR2_PACKAGE_GIT=y
BR2_PACKAGE_HTOP=y
BR2_PACKAGE_LSOF=y
BR2_PACKAGE_MSMTP=y
BR2_PACKAGE_NANO=y
BR2_PACKAGE_PWGEN=y
BR2_PACKAGE_RSYNC=y
BR2_PACKAGE_SUDO=y
BR2_PACKAGE_TMUX=y

BR2_PACKAGE_DEJAVU=y
BR2_PACKAGE_DEJAVU_MONO=y
BR2_PACKAGE_DEJAVU_SANS=y
BR2_PACKAGE_DEJAVU_SERIF=y
BR2_PACKAGE_DEJAVU_SANS_CONDENSED=y
BR2_PACKAGE_DEJAVU_SERIF_CONDENSED=y

BR2_PACKAGE_DROPBEAR=y
BR2_PACKAGE_GESFTPSERVER=y

BR2_PACKAGE_LIBCURL=y
BR2_PACKAGE_LIBCURL_CURL=y

BR2_PACKAGE_LIGHTTPD=y
BR2_PACKAGE_LIGHTTPD_PCRE=y

BR2_PACKAGE_NTP=y
BR2_PACKAGE_NTP_NTPD=n
BR2_PACKAGE_NTP_NTPDATE=y

BR2_PACKAGE_DHCPCD=n
BR2_PACKAGE_IFUPDOWN=y
BR2_PACKAGE_IFUPDOWN_SCRIPTS=y
BR2_PACKAGE_IPROUTE2=y

BR2_PACKAGE_WIRELESS_TOOLS=y
BR2_PACKAGE_WIRELESS_TOOLS_LIB=y

BR2_PACKAGE_WPA_SUPPLICANT=y
BR2_PACKAGE_WPA_SUPPLICANT_NL80211=y
BR2_PACKAGE_WPA_SUPPLICANT_AUTOSCAN=y
BR2_PACKAGE_WPA_SUPPLICANT_WPS=y
BR2_PACKAGE_WPA_SUPPLICANT_WPA3=y
BR2_PACKAGE_WPA_SUPPLICANT_CLI=y
BR2_PACKAGE_WPA_SUPPLICANT_WPA_CLIENT_SO=y
BR2_PACKAGE_WPA_SUPPLICANT_PASSPHRASE=y

BR2_PACKAGE_MESA3D=y
BR2_PACKAGE_MESA3D_GALLIUM_DRIVER_VC4=y
BR2_PACKAGE_MESA3D_OPENGL_EGL=y
BR2_PACKAGE_MESA3D_OPENGL_ES=y

BR2_PACKAGE_WESTON=y
BR2_PACKAGE_WESTON_DEFAULT_DRM=y

BR2_PACKAGE_COG=y
BR2_PACKAGE_COG_PROGRAMS_HOME_URI="http://127.0.0.1/"
BR2_PACKAGE_WPEWEBKIT=y
BR2_PACKAGE_WPEWEBKIT_MULTIMEDIA=y
BR2_PACKAGE_WPEWEBKIT_WEBDRIVER=y

[bnoordhuis]

@dusan-ivanco Can you post the output of strace -T -tt node -e "console.log('Node.js loaded');"? If it's too unwieldy, insert -o trace.log before -T to capture it to file.

It could be that it's stuck trying to read from e.g. /dev/urandom; strace will show that.

[dusan-ivanco]

Yes, you are right

`16:44:29.145641 getpid() = 380 <0.000074>

16:44:29.158906 getrandom("\x20\xcf\x03\x1c\x96\x5e\x77\x9f\x41\xf3\xf5\xe6\x7e\xcd\x88\x96\x65\x4c\xf8\x96\x86\x77\x88\x2b\xb3\x2f\x1a\x85\xed\x8d\xf6\xf9", 32, 0) = 32 <189.181546>

16:47:38.341138 getpid() = 380 <0.000088>
`

but why? why build 11 is ok?

[bnoordhuis]

It's an openssl bug that was fixed recently-ish - it didn't always wait until sufficient entropy is available. Node.js v11.x is out of support so it didn't (and won't) get the fix.

I'm going to close the issue because it's ultimately a problem with your system, not node. Google around for "getrandom slow" to find out more.