Slow (8m 30s) restart time on raspberry pi 4B

I don’t know if this is a general problem or is specific to my device (raspberry pi 4B). Boot up and shutdown times are longer than I would expect.

When the boot sequence gets to setting up the firewall, things seem to not progress for 2m 15s. Why does that take so long? Near the end of the boot sequence, the DHCP request on the red interface looks like it takes 1m 40s. Again, is that to be expected?

For shutdown, things pause at shutting down DHCP on the red interface. That lasts for about 1m 15s when it says it failed to stop dhcpcd and then continues to shutdown.

Are these delays just for aarch64, or are others seeing them? Is there anything I can do to speed things up?

pygr

my first thought would be a failure of the non-volatile memory, especially if you use an SD card. I would try a new card and see if the problem goes away. Also, I would have a look to the system logs (they are in /var/log/messages in the console).

1 Like

Hi cfusco, thank you for the reply. It’s possible that mass storage failure might be the problem, but it will take some time to acquire a replacement. The reason is there is no SD card present. Mass storage is a low power SSD (SanDisk SSD0E97864 16GB – 250mA) connected with USB ( SSK Aluminum M.2 NVME SSD Enclosure). The system can run for months at a time without issue.

I checked /var/log/messages, but all I saw was log entries for firewall hits. Digging into the System Logs area of the webui, I found the RED section looks like a dhcpcd log:

IPFire diagnostics
Section: red
Date: March 02, 2023

08:23:21 dhcpcd[4082] : red0: adding default route via 108.169.4.1
08:23:21 dhcpcd[4082] : red0: adding route to 108.169.4.0/24
08:23:21 dhcpcd[4082] : red0: leased 108.169.4.226 for 1200 seconds
08:23:16 dhcpcd[4082] : red0: probing address 108.169.4.226/24
08:23:16 dhcpcd[4082] : red0: offered 108.169.4.226 from 108.169.4.1
08:23:16 dhcpcd[4082] : red0: soliciting a DHCP lease
08:23:14 dhcpcd[4082] : red0: IAID ff:00:00:02
08:23:14 dhcpcd[4082] : DUID 00:01:00:01:29:49:2a:1f:02:d2:19:eb:99:1e
08:23:14 dhcpcd[4079] : dhcpcd-9.4.1 starting
08:20:46 dhcpcd[4080] : main: control_stop: No such file or directory
08:20:39 dhcpcd[24186] : waiting for pid 4079 to exit
08:20:39 dhcpcd[24186] : sending signal ALRM to pid 4079
08:20:38 dhcpcd[24108] : pid 4079 failed to exit
08:20:28 dhcpcd[24108] : waiting for pid 4079 to exit
08:20:28 dhcpcd[24108] : sending signal ALRM to pid 4079
08:20:27 dhcpcd[23983] : pid 4079 failed to exit
08:20:17 dhcpcd[23983] : waiting for pid 4079 to exit
08:20:17 dhcpcd[23983] : sending signal ALRM to pid 4079
08:20:16 dhcpcd[23753] : pid 4079 failed to exit
08:20:06 dhcpcd[23753] : waiting for pid 4079 to exit
08:20:06 dhcpcd[23753] : sending signal ALRM to pid 4079
08:20:05 dhcpcd[23578] : pid 4079 failed to exit
08:19:55 dhcpcd[23578] : waiting for pid 4079 to exit
08:19:55 dhcpcd[23578] : sending signal ALRM to pid 4079
08:19:54 dhcpcd[23431] : pid 4079 failed to exit
08:19:44 dhcpcd[23431] : waiting for pid 4079 to exit
08:19:44 dhcpcd[23431] : sending signal ALRM to pid 4079
08:19:43 dhcpcd[23022] : pid 4079 failed to exit
08:19:33 dhcpcd[4080] : red0: deleting default route via 108.169.4.1
08:19:33 dhcpcd[4080] : red0: deleting route to 108.169.4.0/24
08:19:33 dhcpcd[4080] : red0: releasing lease of 108.169.4.218
08:19:33 dhcpcd[4080] : red0: removing interface
08:19:33 dhcpcd[4080] : received SIGALRM, releasing
08:19:33 dhcpcd[23022] : waiting for pid 4079 to exit
08:19:33 dhcpcd[23022] : sending signal ALRM to pid 4079

At 08:23:14 dhcpcd starts and seven seconds later it looks like the WAN interface is all set up and ready to go.

Another anomaly that is present may or may not be related: the bootdelay in u-boot is set to 2. That is supposed to be in seconds, but I consistently see the u-boot count down go from 2 to 1 in 10 seconds during bootup!

pygr

what happens before 08:19:33?

probably not the mass storage then. It looks like the dhcpcd problem would explain at least part of the delay. I do not understand what is the problem there. Hoepfully you get some suggestion from more competent people here.

For those interested, here is another part of my setup of IPFire on a raspberry pi 4B:

The RED and GREEN interfaces both use the one ethernet port. The virtual separation is effected with vlan functionality. The physical separation is implemented with a managed switch (TRENDNET TEG-S80ES).

pygr

FWIW -

My RPi4B takes about 90 seconds to power off from IPFire WebGUI shutdown to blinky green LED not lit.

The same RPi4B takes about 60-75 seconds to power up from plug in power to IPFire WebGUI active.

Checked with:
Raspberry Pi 4 Model B Rev 1.1
IPFire 2.27 (aarch64) - Core-Update 173

I do not use vlan so I can not help there…

I’ve seen red interface DHCP take a l-o-n-g time when the ipfire device cannot access the internet (or grab the red interface DHCP IP address).

1 Like

I initiated restart from the console. That’s the complete dhcpcd log up to that time for March 2.

pygr