<html>
<head>
<meta http-equiv="content-type" content="text/html; charset=UTF-8">
</head>
<body>
In a recent kernel(5.x) / Buildroot / Busybox for an embedded system
(mips/MT7628, if it matters) I see TONS of:
<pre><code>random: mount: uninitialized urandom read (4 bytes read)
random: fsck.vfat: uninitialized urandom read (4 bytes read)
random: tar: uninitialized urandom read (4 bytes read)
(Complete startup log below)
</code></pre>
<p>This stops when, after a while (up to 10min later!!) I finally
see:</p>
<code>[ 562.001438] random: crng init done
</code>
<p>Two questions:</p>
<ol>
<li>why does it take so long to initialize /dev/urandom?</li>
<li>for what reason <code>mount</code> or <code>tar</code>
should try to use it in the first place?</li>
</ol>
<p>Note: I did NOT have this problem with older kernels (3.x).</p>
<pre>Starting kernel ...
[ 0.000000] Linux version 5.3.0 (mcon@cinderella) (gcc version 8.3.0 (Buildroot 2019.11-git-01046-g084c788231-dirty)) #2 PREEMPT Mon Nov 11 21:34:58 CET 2019
[ 0.000000] Board has DDR2
[ 0.000000] Analog PMU set to hw control
[ 0.000000] Digital PMU set to hw control
[ 0.000000] SoC Type: MediaTek MT7628AN ver:1 eco:2
[ 0.000000] printk: bootconsole [early0] enabled
[ 0.000000] CPU0 revision is: 00019655 (MIPS 24KEc)
[ 0.000000] MIPS: machine is VoCore2
[ 0.000000] Determined physical RAM map:
[ 0.000000] memory: 08000000 @ 00000000 (usable)
[ 0.000000] Initial ramdisk at: 0x86000000 (15000000 bytes)
[ 0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
[ 0.000000] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[ 0.000000] Zone ranges:
[ 0.000000] Normal [mem 0x0000000000000000-0x0000000007ffffff]
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000000000000-0x0000000007ffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 32480
[ 0.000000] Kernel command line: console=ttyS2,115200 root=/dev/mtdblock4 rootfstype=squashfs USE=SD rd_start=0x86000000 rd_size=15000000 USE=ash
[ 0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
[ 0.000000] Writing ErrCtl register=00016eb9
[ 0.000000] Readback ErrCtl register=00016eb9
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] Memory: 110004K/131072K available (4084K kernel code, 221K rwdata, 480K rodata, 200K init, 95K bss, 21068K reserved, 0K cma-reserved)
[ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] rcu: Preemptible hierarchical RCU implementation.
[ 0.000000] Tasks RCU enabled.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[ 0.000000] NR_IRQS: 256
[ 0.000000] intc: using register map from devicetree
[ 0.000000] random: get_random_bytes called from 0x804aea4c with crng_init=0
[ 0.000000] CPU Clock: 580MHz
[ 0.000000] timer_probe: no matching timers found
[ 0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6590553264 ns
[ 0.000012] sched_clock: 32 bits at 290MHz, resolution 3ns, wraps every 7405115902ns
[ 0.007684] Console: colour dummy device 80x25
[ 0.011952] Calibrating delay loop... 385.84 BogoMIPS (lpj=1929216)
[ 0.073515] pid_max: default: 4096 minimum: 301
[ 0.078101] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[ 0.085130] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[ 0.095082] rcu: Hierarchical SRCU implementation.
[ 0.100402] devtmpfs: initialized
[ 0.107561] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.117133] futex hash table entries: 16 (order: -5, 192 bytes, linear)
[ 0.123677] pinctrl core: initialized pinctrl subsystem
[ 0.131200] NET: Registered protocol family 16
[ 0.148106] ralink_reboot_setup
[ 0.199926] cdmm: Failed to register CPU notifier
[ 0.210350] vgaarb: loaded
[ 0.214102] SCSI subsystem initialized
[ 0.220826] clocksource: Switched to clocksource MIPS
[ 0.266316] NET: Registered protocol family 2
[ 0.273423] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear)
[ 0.281663] TCP established hash table entries: 1024 (order: 0, 4096 bytes, linear)
[ 0.289023] TCP bind hash table entries: 1024 (order: 0, 4096 bytes, linear)
[ 0.296107] TCP: Hash tables configured (established 1024 bind 1024)
[ 0.302482] UDP hash table entries: 256 (order: 0, 4096 bytes, linear)
[ 0.308760] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes, linear)
[ 0.315929] NET: Registered protocol family 1
[ 0.320109] PCI: CLS 0 bytes, default 32
[ 0.324335] Unpacking initramfs...
[ 2.353534] Freeing initrd memory: 14648K
[ 2.359755] Initialise system trusted keyrings
[ 2.365210] workingset: timestamp_bits=14 max_order=15 bucket_order=1
[ 2.405651] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 2.570831] random: fast init done
[ 3.189993] Key type asymmetric registered
[ 3.194018] Asymmetric key parser 'x509' registered
[ 3.198685] io scheduler mq-deadline registered
[ 3.206138] pinctrl-single 10000060.pinmux: 64 pins, size 8
[ 3.214339] mt7621_gpio 10000600.gpio: registering 32 gpios
[ 3.221208] mt7621_gpio 10000600.gpio: registering 32 gpios
[ 3.227648] mt7621_gpio 10000600.gpio: registering 32 gpios
[ 3.236028] Serial: 8250/16550 driver, 3 ports, IRQ sharing disabled
[ 3.246740] 10000c00.uartlite: ttyS0 at MMIO 0x10000c00 (irq = 28, base_baud = 2500000) is a 16550A
[ 3.258172] 10000d00.uart1: ttyS1 at MMIO 0x10000d00 (irq = 29, base_baud = 2500000) is a 16550A
[ 3.268804] 10000e00.uart2: ttyS2 at MMIO 0x10000e00 (irq = 30, base_baud = 2500000) is a 16550A
[ 3.277953] printk: console [ttyS2] enabled
[ 3.277953] printk: console [ttyS2] enabled
[ 3.286535] printk: bootconsole [early0] disabled
[ 3.286535] printk: bootconsole [early0] disabled
[ 3.299078] spi-mt7621 10000b00.spi: sys_freq: 193333333
[ 3.306804] m25p80 spi0.0: found gd25q128, expected m25p80
[ 3.314675] m25p80 spi0.0: gd25q128 (16384 Kbytes)
[ 3.321949] 5 fixed-partitions partitions found on MTD device spi0.0
[ 3.328404] Creating 5 MTD partitions on "spi0.0":
[ 3.334004] 0x000000000000-0x000000040000 : "u-boot"
[ 3.341376] 0x000000040000-0x000000050000 : "u-boot-env"
[ 3.349430] 0x000000050000-0x000000300000 : "kernel"
[ 3.357373] 0x000000300000-0x000000ff0000 : "filesystem"
[ 3.365589] 0x000000ff0000-0x000001000000 : "firmware"
[ 3.401862] hidraw: raw HID events driver (C) Jiri Kosina
[ 3.408546] NET: Registered protocol family 17
[ 3.413303] Key type dns_resolver registered
[ 3.419727] Loading compiled-in X.509 certificates
[ 3.427418] Freeing unused kernel memory: 200K
[ 3.432151] This architecture does not have kernel memory protection.
[ 3.438770] Run /init as init process
Welcome to VoCore2
[ 3.473529] random: echo: uninitialized urandom read (4 bytes read)
Test shell...
[ 3.485718] random: ash: uninitialized urandom read (4 bytes read)
/bin/ash: can't access tty; job control turned off
/ # [ 3.557878] mmc0: host does not support reading read-only switch, assuming write-enable
[ 3.566079] mmc0: new SDHC card at address e624
[ 3.588835] mmcblk0: mmc0:e624 SL08G 7.40 GiB
[ 3.615254] mmcblk0: p1 p2 p3 p4 < p5 p6 >
/ # modprobe usb_storage
odprobe ehci-platform
sleep 3
mount /dev/sda1 /mn[ 19.474900] random: modprobe: uninitialized urandom read (4 bytes read)
t
ls -la /mnt
[ 19.499262] usbcore: registered new interface driver usbfs
[ 19.505547] usbcore: registered new interface driver hub
[ 19.511736] usbcore: registered new device driver usb
[ 19.522789] usbcore: registered new interface driver usb-storage
/ # modprobe ehci-platform
[ 19.534743] random: modprobe: uninitialized urandom read (4 bytes read)
[ 19.550272] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 19.558227] ehci-platform: EHCI generic platform driver
[ 19.574329] phy phy-10120000.usb-phy.0: remote usb device wakeup disabled
[ 19.581356] phy phy-10120000.usb-phy.0: UTMI 16bit 30MHz
[ 19.586751] ehci-platform 101c0000.ehci: EHCI Host Controller
[ 19.592709] ehci-platform 101c0000.ehci: new USB bus registered, assigned bus number 1
[ 19.601288] ehci-platform 101c0000.ehci: irq 26, io mem 0x101c0000
[ 19.630843] ehci-platform 101c0000.ehci: USB 2.0 started, EHCI 1.00
[ 19.638692] hub 1-0:1.0: USB hub found
[ 19.642960] hub 1-0:1.0: 1 port detected
/ # sleep 3
[ 19.653947] random: sleep: uninitialized urandom read (4 bytes read)
[ 20.010859] usb 1-1: new high-speed USB device number 2 using ehci-platform
[ 20.212796] hub 1-1:1.0: USB hub found
[ 20.217001] hub 1-1:1.0: 4 ports detected
[ 20.640853] usb 1-1.1: new high-speed USB device number 3 using ehci-platform
[ 20.894562] usb-storage 1-1.1:1.0: USB Mass Storage device detected
[ 20.901846] scsi host0: usb-storage 1-1.1:1.0
[ 21.942009] scsi 0:0:0:0: Direct-Access VendorCo ProductCode 2.00 PQ: 0 ANSI: 4
[ 21.952452] sd 0:0:0:0: [sda] 30720000 512-byte logical blocks: (15.7 GB/14.6 GiB)
[ 21.962167] sd 0:0:0:0: [sda] Write Protect is off
[ 21.967774] sd 0:0:0:0: [sda] No Caching mode page found
[ 21.973279] sd 0:0:0:0: [sda] Assuming drive cache: write through
[ 21.988416] sda: sda1 sda2 sda3 sda4 < sda5 sda6 >
[ 21.999679] sd 0:0:0:0: [sda] Attached SCSI removable disk
/ # mount /dev/sda1 /mnt
[ 22.667405] random: mount: uninitialized urandom read (4 bytes read)
[ 22.714184] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
/ # ls -la /mnt
[ 22.728922] random: ls: uninitialized urandom read (4 bytes read)
total 71420
drwxr-xr-x 2 root root 16384 Jan 1 00:00 .
drwxr-xr-x 17 root root 0 Jan 1 00:00 ..
-rwxr-xr-x 1 root root 113824 Nov 11 2019 barebox.bin
-rwxr-xr-x 1 root root 5083292 Nov 11 2019 initram.cpio.xz
-rwxr-xr-x 1 root root 13393920 Nov 11 2019 lower.squash
-rwxr-xr-x 1 root root 49582080 Nov 11 2019 middle.tar
-rwxr-xr-x 1 root root 437352 Oct 14 2019 u-boot-dtb.bin
-rwxr-xr-x 1 root root 433780 Oct 14 2019 u-boot-nodtb.bin
-rwxr-xr-x 1 root root 2317074 Nov 11 2019 uImage
-rwxr-xr-x 1 root root 1751040 Nov 11 2019 upper.tar
/ # ls -la
[ 46.593354] random: ls: uninitialized urandom read (4 bytes read)
total 24
drwxr-xr-x 17 root root 0 Jan 1 00:00 .
drwxr-xr-x 17 root root 0 Jan 1 00:00 ..
-rw------- 1 root root 92 Jan 1 00:00 .ash_history
drwxr-xr-x 2 root root 0 Nov 11 2019 bin
drwxr-xr-x 3 root root 2620 Jan 1 00:00 dev
drwxr-xr-x 11 root root 0 Nov 11 2019 etc
-r-x------ 1 root root 1179 Nov 11 2019 init
drwxr-xr-x 4 root root 0 Nov 11 2019 lib
lrwxrwxrwx 1 root root 3 Nov 11 2019 lib32 -> lib
drwxr-xr-x 2 root root 0 Oct 19 2019 media
drwxr-xr-x 2 root root 16384 Jan 1 00:00 mnt
drwxr-xr-x 2 root root 0 Oct 19 2019 opt
dr-xr-xr-x 39 root root 0 Jan 1 00:00 proc
drwx------ 3 root root 0 Nov 11 2019 root
drwxr-xr-x 3 root root 0 Nov 11 2019 run
drwxr-xr-x 2 root root 0 Nov 11 2019 sbin
dr-xr-xr-x 11 root root 0 Jan 1 00:00 sys
drwxrwxrwt 2 root root 0 Oct 19 2019 tmp
drwxr-xr-x 8 root root 0 Nov 11 2019 usr
drwxr-xr-x 5 root root 0 Nov 11 2019 var
/ # cat /proc/partitions
[ 86.953719] random: cat: uninitialized urandom read (4 bytes read)
major minor #blocks name
31 0 16384 mtdblock0
31 1 256 mtdblock1
31 2 64 mtdblock2
31 3 2752 mtdblock3
31 4 13248 mtdblock4
31 5 64 mtdblock5
179 0 7761920 mmcblk0
179 1 131072 mmcblk0p1
179 2 2097152 mmcblk0p2
179 3 163840 mmcblk0p3
179 4 1 mmcblk0p4
179 5 1048576 mmcblk0p5
179 6 1048576 mmcblk0p6
8 0 15360000 sda
8 1 131072 sda1
8 2 1048576 sda2
8 3 16384 sda3
8 4 1 sda4
8 5 1048576 sda5
8 6 1048576 sda6
/ # [ 194.204065] random: crng init done
<code></code></pre>
</body>
</html>