Pi OS Bookworm and 3.5-rc.1 SBC Mode
-
This may be premature since Bookworm was just released last week, but...
DWC is breaking when running Pi OS Bookworm and 3.5-rc.1 in SBC mode
Testbed setup:
Duet 6HC v1.01A (new)
Pi 4 Model B, 4GB (new)Clean install of Pi OS Bookworm (Debian 12) from 10/10/2023
Installed stable release of 3.4.6 DSF/DWC/RepRap
Result: DWC works, everything works as it did with Pi OS Bullseye (Debian 11)Switched to unstable packages as I normally have in the past per:
https://docs.duet3d.com/User_manual/Machine_configuration/DSF_RPi
Result: After all updates to 3.5.0-rc1, cannot connect to DWC via web browser. Looks like it's in a constant retry loop...
If I revert back to 3.4.6 (per same document), DWC starts working again.
Screen grab of 3.5-rc1:
Here's the log after an update to 3.5-rc1:
Oct 17 15:16:04 nf000000 DuetControlServer[10694]: Duet Control Server v3.5.0-rc.1 Oct 17 15:16:04 nf000000 DuetControlServer[10694]: Written by Christian Hammacher for Duet3D Oct 17 15:16:04 nf000000 DuetControlServer[10694]: Licensed under the terms of the GNU Public License Version 3 Oct 17 15:16:05 nf000000 DuetControlServer[10694]: [info] Settings loaded Oct 17 15:16:05 nf000000 DuetControlServer[10694]: [warn] Kernel SPI buffer size is smaller than RepRapFirmware buffer size (4096 configured vs 8192 required) Oct 17 15:16:05 nf000000 DuetControlServer[10694]: [info] Connection to Duet established Oct 17 15:16:05 nf000000 DuetControlServer[10694]: [info] IPC socket created at /run/dsf/dcs.sock Oct 17 15:16:05 nf000000 systemd[1]: Started duetcontrolserver.service - Duet Control Server. Oct 17 15:16:07 nf000000 DuetControlServer[10694]: [fatal] Abnormal program termination Oct 17 15:16:07 nf000000 DuetControlServer[10694]: [fatal] SPI task faulted Oct 17 15:16:07 nf000000 DuetControlServer[10694]: System.IO.IOException: Error 90 performing SPI data transfer. Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at LinuxApi.SpiDevice.Transfer(Byte* writeBufferPtr, Byte* readBufferPtr, Int32 buffersLength) in /home/runner/work/Due> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at LinuxApi.SpiDevice.TransferFullDuplex(ReadOnlySpan`1 writeBuffer, Span`1 readBuffer) in /home/runner/work/DuetSoftwa> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at DuetControlServer.SPI.DataTransfer.ExchangeData() in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/s> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at DuetControlServer.SPI.DataTransfer.PerformFullTransfer(Boolean connecting) in /home/runner/work/DuetSoftwareFramewor> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at DuetControlServer.SPI.Interface.Run() in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetContr> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at DuetControlServer.Utility.PriorityThreadRunner.<>c__DisplayClass0_0.<Start>b__0() in /home/runner/work/DuetSoftwareF> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: [fatal] SPI task faulted Oct 17 15:16:07 nf000000 DuetControlServer[10694]: System.IO.IOException: Error 90 performing SPI data transfer. Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at LinuxApi.SpiDevice.Transfer(Byte* writeBufferPtr, Byte* readBufferPtr, Int32 buffersLength) in /home/runner/work/Due> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at LinuxApi.SpiDevice.TransferFullDuplex(ReadOnlySpan`1 writeBuffer, Span`1 readBuffer) in /home/runner/work/DuetSoftwa> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at DuetControlServer.SPI.DataTransfer.ExchangeData() in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/s> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at DuetControlServer.SPI.DataTransfer.PerformFullTransfer(Boolean connecting) in /home/runner/work/DuetSoftwareFramewor> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at DuetControlServer.SPI.Interface.Run() in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetContr> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: at DuetControlServer.Utility.PriorityThreadRunner.<>c__DisplayClass0_0.<Start>b__0() in /home/runner/work/DuetSoftwareF> Oct 17 15:16:07 nf000000 DuetControlServer[10694]: [info] Application has shut down Oct 17 15:16:07 nf000000 systemd[1]: duetcontrolserver.service: Main process exited, code=exited, status=70/SOFTWARE Oct 17 15:16:07 nf000000 systemd[1]: duetcontrolserver.service: Failed with result 'exit-code'. Oct 17 15:16:07 nf000000 systemd[1]: duetcontrolserver.service: Consumed 3.595s CPU time. Oct 17 15:16:07 nf000000 systemd[1]: duetcontrolserver.service: Scheduled restart job, restart counter is at 162. Oct 17 15:16:07 nf000000 systemd[1]: Stopped duetcontrolserver.service - Duet Control Server. Oct 17 15:16:07 nf000000 systemd[1]: duetcontrolserver.service: Consumed 3.595s CPU time. Oct 17 15:16:07 nf000000 systemd[1]: Starting duetcontrolserver.service - Duet Control Server
I see the SPI buffer message 4096 configured vs 8192 required
but I have done:echo "options spidev bufsiz=8192" | sudo tee /etc/modprobe.d/spidev.conf
and I have verified that the file is in /etc/modprobe.d and contains the proper text.
Here's the log after I revert to 3.4.6. You can see the transition from 3.5-rc1 to the first try of 3.4.6:
Oct 17 15:22:13 nf000000 systemd[1]: Starting duetcontrolserver.service - Duet Control Server... Oct 17 15:22:13 nf000000 DuetControlServer[18053]: Duet Control Server v3.5.0-rc.1 Oct 17 15:22:13 nf000000 DuetControlServer[18053]: Written by Christian Hammacher for Duet3D Oct 17 15:22:13 nf000000 DuetControlServer[18053]: Licensed under the terms of the GNU Public License Version 3 Oct 17 15:22:14 nf000000 DuetControlServer[18053]: [info] Settings loaded Oct 17 15:22:14 nf000000 DuetControlServer[18053]: [info] Environment initialized Oct 17 15:22:14 nf000000 DuetControlServer[18053]: [warn] Kernel SPI buffer size is smaller than RepRapFirmware buffer size (4096 configured vs 8192 required) Oct 17 15:22:14 nf000000 DuetControlServer[18053]: [info] Connection to Duet established Oct 17 15:22:14 nf000000 DuetControlServer[18053]: [info] IPC socket created at /run/dsf/dcs.sock Oct 17 15:22:14 nf000000 systemd[1]: Started duetcontrolserver.service - Duet Control Server. Oct 17 15:22:14 nf000000 DuetControlServer[18053]: [info] Starting macro file config.g on channel Trigger Oct 17 15:22:15 nf000000 DuetControlServer[18053]: [info] Finished macro file config.g Oct 17 15:22:39 nf000000 DuetControlServer[18053]: [warn] Received SIGTERM, shutting down... Oct 17 15:22:39 nf000000 systemd[1]: Stopping duetcontrolserver.service - Duet Control Server... Oct 17 15:22:39 nf000000 DuetControlServer[18053]: [info] Application has shut down Oct 17 15:22:39 nf000000 systemd[1]: duetcontrolserver.service: Deactivated successfully. Oct 17 15:22:39 nf000000 systemd[1]: Stopped duetcontrolserver.service - Duet Control Server. Oct 17 15:22:39 nf000000 systemd[1]: duetcontrolserver.service: Consumed 8.961s CPU time. Oct 17 15:22:53 nf000000 systemd[1]: Starting duetcontrolserver.service - Duet Control Server... Oct 17 15:22:53 nf000000 DuetControlServer[18432]: Duet Control Server v3.4.6 Oct 17 15:22:53 nf000000 DuetControlServer[18432]: Written by Christian Hammacher for Duet3D Oct 17 15:22:53 nf000000 DuetControlServer[18432]: Licensed under the terms of the GNU Public License Version 3 Oct 17 15:22:54 nf000000 DuetControlServer[18432]: [info] Settings loaded Oct 17 15:22:54 nf000000 DuetControlServer[18432]: [info] Environment initialized Oct 17 15:22:54 nf000000 DuetControlServer[18432]: [warn] Kernel SPI buffer size is smaller than RepRapFirmware buffer size (4096 configured vs 8192 required) Oct 17 15:22:54 nf000000 DuetControlServer[18432]: [info] Connection to Duet established Oct 17 15:22:54 nf000000 DuetControlServer[18432]: [info] IPC socket created at /run/dsf/dcs.sock Oct 17 15:22:54 nf000000 systemd[1]: Started duetcontrolserver.service - Duet Control Server. lines 953-1000/1000 (END)
I see the same SPI buffer warning but DWC is working.
We want to go to Python 3.11 ASAP so that's why we jumped on Bookworm so quickly. We will try to patiently await suggestions/a fix...
-
@davidjryan Error 90 means "message too long" so you need to figure out why the SPI buffer size isn't adjusted. Even if DSF 3.4.6 starts, you're very likely to get communication problems if that 4096-byte boundary is exceeded.
-
@chrishamm
Thanks for verifying that that was a legitimate error/concern.
By default, does 3.5-rc.1 have large SPI transmissions right off the get-go but 3.4.6 does not? Perhaps that's why 3.4.6 was connecting but not faulting out like 3.5-rc.1?After further testing:
For Bullseye (Deb 11), this works:echo "options spidev bufsiz=8192" | sudo tee /etc/modprobe.d/spidev.conf
For Bookworm (Deb 12), it does not.
Instead, I had to add:
spidev.bufsiz=8192
to the end of
/boot/cmdline.txt
After a reboot, when I:
cat /sys/module/spidev/parameters/bufsiz
I get 8192 and DWC now connects to the 6HC with 3.5-rc.1 in SBC mode.
I know we are probably an early adopter of Bookworm on the Pi w/Duet SBC so I'll report out anything else I run into. We'll be exercising our system heavily over the next few weeks.