NFS boot hangs

I’m having an odd problem trying to boot the BBB over NFS. Specifically, I’m trying to mount the Debian image dated 2017-03-19. Here’s the output I get:

U-Boot SPL 2017.03-00002-gd12b1519b4 (Mar 14 2017 - 10:28:26)
Trying to boot from MMC2

U-Boot 2017.03-00002-gd12b1519b4 (Mar 14 2017 - 10:28:26 -0500), Build: jenkins-
github_Bootloader-Builder-532

CPU : AM335X-GP rev 2.1
I2C: ready
DRAM: 512 MiB
Reset Source: Power-on reset has occurred.
MMC: OMAP SD/MMC: 0, OMAP SD/MMC: 1
Using default environment

not set. Validating first E-fuse MAC
BeagleBone Black:
BeagleBone: cape eeprom: i2c_probe: 0x54:
BeagleBone: cape eeprom: i2c_probe: 0x55:
BeagleBone: cape eeprom: i2c_probe: 0x56:
BeagleBone: cape eeprom: i2c_probe: 0x57:
Net: eth0: MII MODE
cpsw
Press SPACE to abort autoboot in 2 seconds
board_name=[A335BNLT] …
board_rev=[000C] …
switch to partitions #0, OK
mmc0 is current device
SD/MMC found on device 0
** Bad device 0:2 0x82000000 **
** Bad device 0:2 0x82000000 **
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1…
gpio: pin 56 (gpio 56) value is 0
gpio: pin 55 (gpio 55) value is 0
gpio: pin 54 (gpio 54) value is 0
gpio: pin 53 (gpio 53) value is 1
switch to partitions #0, OK
mmc0 is current device
gpio: pin 54 (gpio 54) value is 1
Checking for: /uEnv.txt …
1650 bytes read in 30 ms (53.7 KiB/s)
gpio: pin 55 (gpio 55) value is 1
Loaded environment from /uEnv.txt
Importing environment from mmc …
Checking if uenvcmd is set …
gpio: pin 56 (gpio 56) value is 1
Running uenvcmd …
1483 bytes read in 37 ms (39.1 KiB/s)
debug: [/boot/vmlinuz-4.4.54-ti-r93] …
8652712 bytes read in 576 ms (14.3 MiB/s)
debug: [/boot/initrd.img-4.4.54-ti-r93] …
5035153 bytes read in 346 ms (13.9 MiB/s)
debug: [/boot/dtbs/4.4.54-ti-r93/am335x-boneblack.dtb] …
56827 bytes read in 113 ms (490.2 KiB/s)
debug: [console=tty0 console=ttyO0,115200n8 root=/dev/nfs nfsroot=192.168.1.2:/h
ome/doug/bbbfs rootfstype=ext4 rootwait fixrtc coherent_pool=1M net.ifnames=0 qu
iet cape_universal=enable] …
debug: [bootz 0x82000000 0x88080000:4cd491 0x88000000] …

Flattened Device Tree blob at 88000000

Booting using the fdt blob at 0x88000000
Using Device Tree in place at 88000000, end 88010dfa

Starting kernel …

[ 0.001037] clocksource_probe: no matching clocksources found
[ 2.058506] wkup_m3_ipc 44e11324.wkup_m3_ipc: could not get rproc handle
[ 2.239707] omap_voltage_late_init: Voltage driver support not added
[ 2.247425] PM: Cannot get wkup_m3_ipc handle
Loading, please wait…
[ 4.837347] remoteproc1: failed to load am335x-pru0-fw
[ 4.866502] remoteproc1: request_firmware failed: -2
[ 4.871686] pru-rproc 4a334000.pru0: rproc_boot failed
[ 4.977254] remoteproc1: failed to load am335x-pru1-fw
[ 4.983007] remoteproc1: request_firmware failed: -2
[ 4.988172] pru-rproc 4a338000.pru1: rproc_boot failed
IP-Config: eth0 hardware address 80:30:dc:90:9b:da mtu 1500 DHCP RARP
IP-Config: no response after 2 secs - giving up
IP-Config: eth0 hardware address 80:30:dc:90:9b:da mtu 1500 DHCP RARP
IP-Config: eth0 guessed broadcast address 192.168.1.255
IP-Config: eth0 complete (dhcp from 192.168.1.1):
address: 192.168.1.128 broadcast: 192.168.1.255 netmask: 255.255.255.0
gateway: 192.168.1.1 dns0 : 192.168.1.1 dns1 : 0.0.0.0
rootserver: 192.168.1.1 rootpath:
filename :
[FAILED] Failed to start Create Volatile Files and Directories.
See ‘systemctl status systemd-tmpfiles-setup.service’ for details.
[FAILED] Failed to start Network Time Synchronization.
See ‘systemctl status systemd-timesyncd.service’ for details.
[ OK ] Reached target System Time Synchronized.
Starting Update UTMP about System Boot/Shutdown…
[ OK ] Started udev Kernel Device Manager.
[ OK ] Stopped Network Time Synchronization.
[FAILED] Failed to start Network Time Synchronization.
See ‘systemctl status systemd-timesyncd.service’ for details.
Starting LSB: Tune IDE hard disks…
[ OK ] Stopped Network Time Synchronization.
[FAILED] Failed to start Network Time Synchronization.
See ‘systemctl status systemd-timesyncd.service’ for details.
[ OK ] Stopped Network Time Synchronization.
[FAILED] Failed to start Network Time Synchronization.
See ‘systemctl status systemd-timesyncd.service’ for details.
[FAILED] Failed to start Update UTMP about System Boot/Shutdown.
See ‘systemctl status systemd-update-utmp.service’ for details.
[DEPEND] Dependency failed for Update UTMP about System Runlevel Changes.
[ OK ] Stopped Network Time Synchronization.
[FAILED] Failed to start Network Time Synchronization.
See ‘systemctl status systemd-timesyncd.service’ for details.
[ OK ] Stopped Network Time Synchronization.
[FAILED] Failed to start Network Time Synchronization.
See ‘systemctl status systemd-timesyncd.service’ for details.
[ OK ] Started LSB: Tune IDE hard disks.
[ OK ] Reached target System Initialization.
[ OK ] Listening on bonescript.socket.
[ OK ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
[ OK ] Listening on D-Bus System Message Bus Socket.
[ OK ] Listening on node-red.socket.
[ OK ] Listening on cloud9.socket.
[ OK ] Reached target Sockets.
Starting Restore Sound Card State…
[ OK ] Started Daily Cleanup of Temporary Directories.
[ OK ] Reached target Timers.
[ OK ] Reached target Basic System.
[ OK ] Started Bonescript autorun.
Starting Login Service…
Starting BB WL18xx wlan0 Service…
[ OK ] Started Regular background program processing daemon.
Starting Restore /etc/resolv.conf i…e the ppp link was shut down…
[ OK ] Started D-Bus System Message Bus.
Starting Connection service…
Starting Cape Manager Service…
Starting LSB: Load kernel modules needed to enable cpufreq scaling…
[ OK ] Started Deferred execution scheduler.
Starting LSB: Start busybox udhcpd at boot time…
Starting Generic Board Startup…
[ OK ] Started Entropy daemon using the HAVEGE algorithm.
Starting System Logging Service…
Starting Avahi mDNS/DNS-SD Stack…
[ OK ] Started Restore Sound Card State.
[ OK ] Started BB WL18xx wlan0 Service.
[ OK ] Started Restore /etc/resolv.conf if…ore the ppp link was shut down…
[ OK ] Started Login Service.
[ OK ] Started Cape Manager Service.
[ OK ] Started Avahi mDNS/DNS-SD Stack.
[ OK ] Started System Logging Service.
[ OK ] Started Connection service.
[ OK ] Started LSB: Start busybox udhcpd at boot time.
[ 240.434285] INFO: task kworker/0:0:4 blocked for more than 120 seconds.
[ 240.441010] Not tainted 4.4.54-ti-r93 #1
[ 240.445518] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this

message.
[ 240.453725] INFO: task kworker/0:3:547 blocked for more than 120 seconds.
[ 240.460572] Not tainted 4.4.54-ti-r93 #1
[ 240.465056] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this
message.

It looks like everything is going pretty well until the “Started LSB: Start busybox udhcpd at boot time.” message. Then it just hangs until the next six lines come out four minutes later and repeat every two minutes. No kernel panic, but also no login prompt. What am I missing?

TIA

I’ve been playing around with this most of the day and I think I’ve made some progress. I think the nfs-uEnv.txt script that comes with Debian 8.6 is missing some stuff. First off, it doesn’t load the initrd file. From what I can tell that seems to be necessary. Then there are some command line options that the MMC boot script defines that aren’t in the NFS script.

So I modified nfsboot_uname_r to load the initrd and pass it to the kernel. Here is my cmdline:
cmdline=quiet coherent_pool=1M net.iframes=0 cape_universal=enable

This seems to get me farther, I think.

Starting kernel …

[ 0.001033] clocksource_probe: no matching clocksources found
[ 2.058442] wkup_m3_ipc 44e11324.wkup_m3_ipc: could not get rproc handle
[ 2.239713] omap_voltage_late_init: Voltage driver support not added
[ 2.247404] PM: Cannot get wkup_m3_ipc handle
Loading, please wait…
[ 7.889354] remoteproc1: failed to load am335x-pru0-fw
[ 7.919494] remoteproc1: request_firmware failed: -2
[ 7.924703] pru-rproc 4a334000.pru0: rproc_boot failed
[ 8.045662] remoteproc1: failed to load am335x-pru1-fw
[ 8.063312] remoteproc1: request_firmware failed: -2
[ 8.068516] pru-rproc 4a338000.pru1: rproc_boot failed
IP-Config: eth0 hardware address 80:30:dc:90:9b:da mtu 1500
IP-Config: eth0 guessed broadcast address 192.168.1.255
IP-Config: eth0 complete:
address: 192.168.1.50 broadcast: 192.168.1.255 netmask: 255.255.255.0
gateway: 192.168.1.1 dns0 : 0.0.0.0 dns1 : 0.0.0.0
rootserver: 192.168.1.2 rootpath:
filename :
[ OK ] Started Flush Journal to Persistent Storage.
Starting Create Volatile Files and Directories…
[ OK ] Started udev Kernel Device Manager.
Starting LSB: Tune IDE hard disks…
[ OK ] Started udev Coldplug all Devices.
[ OK ] Started Create Volatile Files and Directories.
Starting Update UTMP about System Boot/Shutdown…
Starting Network Time Synchronization…
[ OK ] Started LSB: Tune IDE hard disks.
[ OK ] Started Update UTMP about System Boot/Shutdown.
[ OK ] Started Network Time Synchronization.
[ OK ] Reached target System Time Synchronized.
[ OK ] Reached target System Initialization.
[ OK ] Listening on bonescript.socket.
[ OK ] Listening on cloud9.socket.
[ OK ] Listening on D-Bus System Message Bus Socket.
[ OK ] Started Daily Cleanup of Temporary Directories.
[ OK ] Reached target Timers.
[ OK ] Listening on node-red.socket.
[ OK ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
[ OK ] Reached target Sockets.
[ OK ] Reached target Basic System.
Starting BB WL18xx wlan0 Service…
Starting Login Service…
[ OK ] Started Regular background program processing daemon.
[ OK ] Started Deferred execution scheduler.
Starting System Logging Service…
Starting LSB: Start busybox udhcpd at boot time…
Starting LSB: Load kernel modules needed to enable cpufreq scaling…
[ OK ] Started Entropy daemon using the HAVEGE algorithm.
Starting Generic Board Startup…
Starting Cape Manager Service…
[ OK ] Started Bonescript autorun.
Starting Restore Sound Card State…
Starting Restore /etc/resolv.conf i…e the ppp link was shut down…
[ OK ] Started D-Bus System Message Bus.
Starting Connection service…
Starting Avahi mDNS/DNS-SD Stack…
[ OK ] Started System Logging Service.
[ OK ] Started BB WL18xx wlan0 Service.
[ OK ] Started Cape Manager Service.
[ OK ] Started Restore Sound Card State.
[ OK ] Started Restore /etc/resolv.conf if…ore the ppp link was shut down…
[ OK ] Started LSB: Start busybox udhcpd at boot time.
[ OK ] Started Login Service.
[ OK ] Started Avahi mDNS/DNS-SD Stack.
[ OK ] Started Connection service.
[ 240.434411] INFO: task kworker/0:8:849 blocked for more than 120 seconds.
[ 240.441295] Not tainted 4.4.54-ti-r93 #1
[ 240.445799] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this
message.
[ 360.450413] INFO: task kworker/0:8:849 blocked for more than 120 seconds.
[ 360.457296] Not tainted 4.4.54-ti-r93 #1
[ 360.461797] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this
message.

I really would like some insight into this. Thanks.