[slx-network] Make scripts much more verbose for better profiling

1 files changed, 37 insertions, 17 deletions

diff --git a/modules.d/slx-network/hooks/s3-setup-bootif-network.sh b/modules.d/slx-network/hooks/s3-setup-bootif-network.sh
index 1aeac9b6..75948867 100755
--- a/modules.d/slx-network/hooks/s3-setup-bootif-network.sh
+++ b/modules.d/slx-network/hooks/s3-setup-bootif-network.sh
@@ -11,15 +11,21 @@ type emergency_shell >/dev/null 2>&1 || . /lib/dracut-lib.sh
 . /run/openslx/network.conf
 
 # do not run until the physical interface exists (driver loaded)
+echo "Waiting for ${SLX_PXE_NETIF} to appear"
 _fails=0
 while ! [ -e "/sys/class/net/${SLX_PXE_NETIF}/device" ]; do
 	if (( ++_fails > 30 )); then
+		echo "Timeout"
 		emergency_shell "Boot interface '${SLX_PXE_NETIF}' did not appear"
 		exit 1
 	fi
-	(( (_fails % 7) == 0 )) && udevadm trigger --subsystem-match=net
-	usleep 333333
+	if (( (_fails % 7) == 0 )); then
+		echo "Triggering udev again..."
+		udevadm trigger --subsystem-match=net &
+	fi
+	usleep 333000
 done
+echo "${SLX_PXE_NETIF}: found"
 
 # wrapper around splashtool to disable it if its not present
 _splashtool() {
@@ -36,17 +42,23 @@ wait_for_iface() {
 	local _timeout="$(( ${2:-50} * 3 ))"
 	local _fails=0
 	local _state
+	local _carrier
 	if [ "$_iface" = "$SLX_PXE_NETIF" ]; then
 		img="??-nic"
 	elif [ "$_iface" = "$SLX_BRIDGE" ]; then
 		img="??-bridge"
 	fi
+	echo "${_iface}: Waiting for link up"
 	while (( _timeout-- > 0 )); do
 		ip link set dev "$_iface" up
 		_state="$(cat "/sys/class/net/${_iface}/operstate" 2> /dev/null)"
 		[ "$_state" = "up" ] && break
 		if (( ++_fails > 5 )) && [[ "$_state" = "unknown" || "$_state" = "" ]]; then
-			if (( _fails > 10 )) || [ "$(cat "/sys/class/net/${_iface}/carrier" 2> /dev/null)" = "1" ]; then
+			# Kernel doesn't report operstate; assume up if we have carrier after 5 iterations,
+			# or just hope for the best after 10 iterations...
+			_carrier="$( cat "/sys/class/net/${_iface}/carrier" 2> /dev/null )"
+			if (( _fails > 10 )) || [ "$_carrier" = "1" ]; then
+				echo "${_iface}: operstate '$_state', carrier '$_carrier', assuming link up..."
 				break
 			fi
 		fi
@@ -57,9 +69,11 @@ wait_for_iface() {
 		_splashtool --icon "/opt/openslx/icons/${in}active/${img}.ppm" &
 	done
 	if (( _timeout > 0 )); then
+		echo "${_iface}: Got link"
 		_splashtool --icon "/opt/openslx/icons/active/${img}.ppm" &
 		return 0
 	else
+		echo "${_iface}: Timeout waiting for link"
 		_splashtool --icon "/opt/openslx/icons/inactive/${img}.ppm" &
 		return 1
 	fi
@@ -70,7 +84,7 @@ wait_for_iface() {
 set -x
 
 if ! wait_for_iface "$SLX_PXE_NETIF" 30; then
-	echo "'$SLX_PXE_NETIF' still not up after 30sec ... trying anyway."
+	echo "$SLX_PXE_NETIF: Still not up after 30sec ... trying anyway."
 	# TODO handle case where we waited for 30sec and it is still not up
 fi
 
@@ -78,6 +92,7 @@ fi
 MAIN_NETIF="$SLX_PXE_NETIF"
 if [ -n "$SLX_VLAN_ID" ]; then
 	# create VLAN interface
+	echo "${SLX_PXE_NETIF}: Adding VLAN ${SLX_VLAN_ID}"
 	modprobe 8021q || echo "Loading '8021q' failed - missing module?"
 	ip link add link "$SLX_PXE_NETIF" name "${SLX_PXE_NETIF}.${SLX_VLAN_ID}" \
 		type vlan id "$SLX_VLAN_ID"
@@ -85,11 +100,12 @@ if [ -n "$SLX_VLAN_ID" ]; then
 	if wait_for_iface "${SLX_PXE_NETIF}.${SLX_VLAN_ID}"; then
 		MAIN_NETIF="${SLX_PXE_NETIF}.${SLX_VLAN_ID}"
 	else
-		echo "Setting up VLAN '$SLX_VLAN_ID' failed, trying plain..."
+		echo "${SLX_PXE_NETIF}: Setting up VLAN '$SLX_VLAN_ID' failed, trying to continue untagged..."
 	fi
 fi
 
 if [ -n "$SLX_BRIDGE" ]; then
+	echo "${SLX_BRIDGE}: Trying to create bridge on ${MAIN_NETIF}"
 	for try in {1..10} ""; do
 		if (
 				set -e
@@ -101,6 +117,7 @@ if [ -n "$SLX_BRIDGE" ]; then
 				ip link set dev "$SLX_BRIDGE" up
 				wait_for_iface "$SLX_BRIDGE"
 		); then
+			echo "${SLX_BRIDGE}: Bridge created successfully"
 			MAIN_NETIF="$SLX_BRIDGE"
 			break
 		fi
@@ -110,7 +127,7 @@ if [ -n "$SLX_BRIDGE" ]; then
 			emergency_shell "Failed to setup main network bridge, giving up!"
 			exit 1
 		fi
-		echo "Failed to setup main network bridge on try $try. Retrying ..."
+		echo "${SLX_BRIDGE}: Failed to setup main network bridge on try $try. Retrying ..."
 		# delete bridge, inc try and sleep 100ms before trying again
 		if [ -e "/sys/class/net/${SLX_BRIDGE}" ]; then
 			ip link set dev "$SLX_BRIDGE" down
@@ -121,23 +138,25 @@ if [ -n "$SLX_BRIDGE" ]; then
 	done
 fi
 
-# Finally add the IP address on the main NIC.
+# Finally add the IP address on the main interface, whatever that is now.
 # Note: we should never have ip & netmask without the other.
 if [ -n "$SLX_PXE_CLIENT_IP" ] && [ -n "$SLX_PXE_NETMASK" ]; then
+	echo "${MAIN_NETIF}: Setting IP configuration"
 	ip addr add "${SLX_PXE_CLIENT_IP}/${SLX_PXE_NETMASK}" dev "$MAIN_NETIF"
 
 	# now if we got everything from the KCL and skip dhcp if so
 	if [ -n "$SLX_PXE_GATEWAY" ] && [ -n "$SLX_PXE_DNS" ]; then
-		echo "Got network configuration from KCL, skipping DHCP."
-		if ! interface="$MAIN_NETIF" \
-			ip="$SLX_PXE_CLIENT_IP" \
-			router="$SLX_PXE_GATEWAY" \
-			dns="$SLX_PXE_DNS" \
-			hostname="$SLX_PXE_HOSTNAME" \
-			/usr/local/bin/udhcpc-trigger bound; then
-			echo "Failed to launch DHCP trigger with KCL configuration - will DHCP."
+		echo "${MAIN_NETIF}: Got network configuration from KCL, skipping DHCP."
+		if interface="$MAIN_NETIF" \
+				ip="$SLX_PXE_CLIENT_IP" \
+				router="$SLX_PXE_GATEWAY" \
+				dns="$SLX_PXE_DNS" \
+				hostname="$SLX_PXE_HOSTNAME" \
+				/usr/local/bin/udhcpc-trigger bound; then
+			exit 0
+		else
+			echo "${MAIN_NETIF}: Failed to launch DHCP trigger with KCL configuration - will DHCP."
 		fi
-		exit 0
 	fi
 fi
 
@@ -170,6 +189,7 @@ request_opts+=("-O" "search")
 request_opts+=("-O" "nisdomain")
 
 # udhcpc
+echo "${MAIN_NETIF}: Running DHCP client..."
 for i in 1 1 1 fail; do
 	if [ "$i" = "fail" ]; then
 		emergency_shell "DHCP failed 3 times... cannot continue."
@@ -182,7 +202,7 @@ for i in 1 1 1 fail; do
 		-s "/usr/local/bin/udhcpc-trigger" \
 		&& break
 	# failed, keep trying...
-	echo "DHCP failed, retrying in $i sec..."
+	echo "${MAIN_NETIF}: DHCP failed, retrying in $i sec..."
 	sleep $i
 done