Hey 🙂
We're using a RaspberryPi Zero W with WittyPi4 in production paired with a solar powerered 30Ah 12V LiFeP04. WittyPi is responsible to shutdown the raspberry pi in the evening and turn it on in the morning again.
It's a RaspberryPi Zero with a Dlink DWM-222 LTE USB Dongle attached.
This is the schedule.wpi:
BEGIN 2015-08-03 05:57:00 END 2025-07-31 23:59:59 ON H14 OFF H10
But something is wrong here...
It was running well for days until it crashed and barely finished booting.
When we got the hardware from the site, neither raspberrypi LED was on, nor WittyPi led was flashing, but the LTE Dongle keeps running as RaspberryPi Zero does not turn off USB powering when shut down.
We changed to a new SD Card, installed everything fresh (same software running without problems on a RaspberryPi Zero without WittyPi, as it has fixed current connection), tested it for one day and brought it back to the site.
Today it crashed again because of unknown reasons.
About a hour later it was online again, and crashed again.
From log files reading Voltage from wittypi every now and then VIn never dropped under 13.25V
But from logs it says:
Mar 11 15:44:10 raspberrypi wittypi[347]: Done :-) Mar 11 15:44:10 raspberrypi wittypi[347]: System was previously shut down because of low-voltage.
Could be related due too the MPPT Solar Driver. As it's not very confidence-inspiring (a-TroniX MPPT X45/10 Solar Laderegler 12V 10A)...
Anyway. We can't fix that right now...
Is there anything we can do? Maybe using the hardware watchdog as described here or? Is there anything we should consider to make it work with the wittypi schedule?
Or is there anything we could check? Even if it is our software that makes the raspberrypi crash, how come it won't turn on again?
Hope to find some help...
After Witty Pi shuts down your Raspberry Pi, it should cut the power after a few seconds delay. That way your Pi and your LTE dongle should all lose power and be off.
What you saw is different: LTE dongle is still powered, which means your Pi is still powered. So I think this is another case that "Witty Pi doesn't cut power after shutdown". Usually it is due to the TXD pin not going LOW after shutdown. It could be because other hardware is strongly pulling it up, or the system crashed during the shutdown.
We did some improvements in the firmware reversion 3, so Witty Pi is able to cut the power even if Raspberry Pi crashed during the shutdown. Please check the wittyPi.log file and confirm the firmware revision of your Witty Pi 4. If the revision is lower than 3, then you can upgrade the firmware to avoid this situation.
Boot log says:
Mar 11 15:44:10 raspberrypi wittypi[347]: Firmware ID: 0x26 Mar 11 15:44:10 raspberrypi wittypi[347]: Firmware Revison: 0x05
As in this case it shut down because of low-voltage: Did wittypi cut power after this ungraceful shutdown?
So at 12:20:38 it died and booted at 15:44
Mar 11 15:44:10 raspberrypi wittypi[347]: System was previously shut down because of low-voltage. Mar 11 15:44:10 raspberrypi wittypi[347]: Firmware ID: 0x26 Mar 11 15:44:10 raspberrypi wittypi[347]: Firmware Revison: 0x05 Mar 11 15:44:10 raspberrypi systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Mar 11 15:44:11 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status... Mar 11 15:44:12 raspberrypi wittypi[347]: Current Vin=13.37V, Vout=5.15V, Iout=0.08A [...] Mar 11 15:44:14 raspberrypi wittypi[347]: System starts up because scheduled startup is due.
What happened in between?
Since you saw "System was previously shut down because of low-voltage." in the log, that event indeed happened because Witty Pi's firmware set a flag in specific register to indicate such situation.
I guess the situation was like this:
- For very short moment the input voltage drop a lot
- Witty Pi's firmware detected that and set the flag in register (also saved in EEPROM)
- voltage drop so quickly that your Pi didn't have enough time to finish the shutdown process
- Your Pi was powered with extremly low voltage (system crashed), but Witty Pi's MCU is still running (it can run even with just 2~3V input)
- input voltage restored and the MCU didn't know about the Pi's system had been crashed
- Pi is powered normally, so is the LTE dongle, but Pi won't boot up
@mmoollllee as far as I remember, the modifications on Rev3 doesn't cover the low-voltage situation. It covers the actions like tapping the button and scheduled shutdown. I think the result of very quick low voltage shutdown is uncertained: if the TXD already goes down then the power will be cut, otherwise not.
Do you have any tips on how to deal with this for stable operation?
So we had the first scheduled shutdown tonight, with the systemd watchdog set to 15sec and power cut delay set to 25sec.
The RaspberryPi started reboot after shutdown and got interupted ungentely I think.
The logs look like this:
Mar 11 18:56:53 raspberrypi wittypi[344]: Shutting down system because scheduled shutdown is due. Mar 11 18:56:54 raspberrypi wittypi[344]: Halting all processes and then shutdown Raspberry Pi... [...] Mar 11 18:57:15 raspberrypi systemd[1]: Shutting down. Mar 11 18:57:15 raspberrypi systemd-shutdown[1]: Syncing filesystems and block devices. Mar 11 18:57:16 raspberrypi systemd-shutdown[1]: Sending SIGTERM to remaining processes... Mar 11 18:57:16 raspberrypi systemd-journald[110]: Journal stopped -- Boot 4efe6c8787ea44d4ac5aa8cf2f8f3c86 -- Mar 11 18:57:17 raspberrypi kernel: Booting Linux on physical CPU 0x0 Mar 11 18:57:17 raspberrypi kernel: Linux version 6.1.21+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1642 Mon Apr 3 17:19:14 BST 2023 [...] Mar 11 18:57:39 raspberrypi systemd[1]: Starting LSB: Witty Pi 4 initialize script... Mar 11 18:57:39 raspberrypi wittypi[343]: Starting Witty Pi 4 Daemon... Mar 11 18:57:43 raspberrypi systemd[1]: Started LSB: Witty Pi 4 initialize script. Mar 11 18:57:55 raspberrypi wittypi[347]: Witty Pi daemon (v4.14) is started. Mar 11 18:57:55 raspberrypi wittypi[347]: Running on Raspberry Pi Zero W Rev 1.1 Mar 11 18:57:55 raspberrypi wittypi[459]: cat: /home/kuckadm1n/Desktop/kuckuck-pi/wittypi/tmp/BUILD-DATA: No such file or directory Mar 11 18:57:56 raspberrypi systemd[1]: home-kuckadm1n-Desktop-kuckuck\x2dpi-wittypi-tmp.mount: Succeeded. Mar 11 18:57:57 raspberrypi wittypi[347]: Seems RTC has good time, write RTC time into system Mar 11 18:57:57 raspberrypi wittypi[347]: Writing RTC time to system... Mar 11 18:57:58 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 139 (plymouthd). Mar 11 18:57:58 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 139 (plymouthd). Mar 11 18:57:58 raspberrypi systemd[1]: Finished Hold until boot process finishes up. Mar 11 18:57:58 raspberrypi kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 Mar 11 18:57:58 raspberrypi systemd[1]: Started Getty on tty1. Mar 11 18:57:58 raspberrypi systemd[1]: Started Serial Getty on ttyAMA0. Mar 11 18:57:58 raspberrypi systemd[1]: Reached target Login Prompts. Mar 11 18:57:58 raspberrypi systemd[1]: Reached target Multi-User System. Mar 11 18:57:58 raspberrypi systemd[1]: Started Light Display Manager. Mar 11 18:57:58 raspberrypi systemd[1]: Reached target Graphical Interface. Mar 11 18:57:59 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes... Mar 11 18:57:59 raspberrypi sudo[520]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-ntp 0 Mar 11 18:57:59 raspberrypi sudo[520]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 11 18:57:59 raspberrypi vncserver-x11[400]: HostedRendezvous: Rendezvous lookup failed: Hosted Bootstrap error: Network failure: Error connecting: getaddrinfo: 'Temporary failure in name resolution' (-3) Mar 11 18:57:59 raspberrypi dbus-daemon[254]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.21' (uid=0 pid=527 comm="timedatectl set-ntp 0 ") Mar 11 18:57:59 raspberrypi vncserver-x11[400]: ConsoleDisplay: Found running X server (pid=519, binary=/usr/lib/xorg/Xorg) Mar 11 18:57:59 raspberrypi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Mar 11 18:57:59 raspberrypi systemd[1]: Finished Update UTMP about System Runlevel Changes. Mar 11 18:57:59 raspberrypi systemd[1]: Startup finished in 4.449s (kernel) + 49.250s (userspace) = 53.700s. Mar 11 18:58:00 raspberrypi systemd[1]: Starting Time & Date Service... Mar 11 18:58:00 raspberrypi login[521]: pam_unix(login:session): session opened for user kuckadm1n(uid=1000) by LOGIN(uid=0) Mar 11 18:58:00 raspberrypi vncserver-x11[400]: AgentInitCheck: agent comms failure Mar 11 18:58:01 raspberrypi systemd[1]: Created slice User Slice of UID 1000. Mar 11 18:58:01 raspberrypi systemd[1]: Starting User Runtime Directory /run/user/1000... Mar 11 18:58:01 raspberrypi systemd-logind[325]: New session 2 of user kuckadm1n. Mar 11 18:58:02 raspberrypi systemd[1]: Finished User Runtime Directory /run/user/1000. Mar 11 18:58:02 raspberrypi systemd[1]: systemd-fsckd.service: Succeeded. Mar 11 18:58:02 raspberrypi systemd[1]: Starting User Manager for UID 1000... Mar 11 18:58:02 raspberrypi systemd[541]: pam_unix(systemd-user:session): session opened for user kuckadm1n(uid=1000) by (uid=0) Mar 11 18:58:02 raspberrypi kernel: brcmfmac: F1 signature read @0x18000000=0x1541a9a6 Mar 11 18:58:02 raspberrypi kernel: Console: switching to colour dummy device 80x30 Mar 11 18:58:03 raspberrypi kernel: vc4-drm soc:gpu: bound 20400000.hvs (ops vc4_hvs_ops [vc4]) Mar 11 18:58:03 raspberrypi kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1 Mar 11 18:58:03 raspberrypi kernel: usbcore: registered new interface driver brcmfmac Mar 11 18:58:03 raspberrypi kernel: Registered IR keymap rc-cec Mar 11 18:58:03 raspberrypi kernel: rc rc0: vc4-hdmi as /devices/platform/soc/20902000.hdmi/rc/rc0 Mar 11 18:58:03 raspberrypi kernel: input: vc4-hdmi as /devices/platform/soc/20902000.hdmi/rc/rc0/input0 Mar 11 18:58:03 raspberrypi kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Jul 19 2021 03:24:18 version 7.45.98 (TOB) (56df937 CY) FWID 01-8e14b897 Mar 11 18:58:03 raspberrypi kernel: vc4-drm soc:gpu: bound 20902000.hdmi (ops vc4_hdmi_ops [vc4]) Mar 11 18:58:03 raspberrypi kernel: vc4-drm soc:gpu: bound 20004000.txp (ops vc4_txp_ops [vc4]) Mar 11 18:58:03 raspberrypi kernel: vc4-drm soc:gpu: bound 20206000.pixelvalve (ops vc4_crtc_ops [vc4]) Mar 11 18:58:03 raspberrypi NetworkManager[275]: <info> [1710183483.6354] device (wlan0): driver supports Access Point (AP) mode Mar 11 18:58:03 raspberrypi NetworkManager[275]: <info> [1710183483.7609] manager: (wlan0): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/2) Mar 11 18:58:04 raspberrypi kernel: vc4-drm soc:gpu: bound 20207000.pixelvalve (ops vc4_crtc_ops [vc4]) Mar 11 18:58:04 raspberrypi kernel: vc4-drm soc:gpu: bound 20807000.pixelvalve (ops vc4_crtc_ops [vc4]) Mar 11 18:58:04 raspberrypi kernel: vc4-drm soc:gpu: bound 20c00000.v3d (ops vc4_v3d_ops [vc4]) Mar 11 18:58:04 raspberrypi dbus-daemon[254]: [system] Successfully activated service 'org.freedesktop.timedate1' Mar 11 18:58:04 raspberrypi systemd[1]: Started Time & Date Service. Mar 11 18:58:04 raspberrypi kernel: [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0 Mar 11 18:58:04 raspberrypi kernel: vc4-drm soc:gpu: [drm] Cannot find any crtc or sizes Mar 11 18:58:04 raspberrypi vncserver-x11[400]: ConsoleDisplay: Cannot find a running X server on vt7 Mar 11 18:58:04 raspberrypi systemd-timedated[533]: Set NTP to disabled. Mar 11 18:58:05 raspberrypi sudo[520]: pam_unix(sudo:session): session closed for user root Mar 11 18:58:05 raspberrypi systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Mar 11 18:58:05 raspberrypi vncserver-x11[400]: AgentInitCheck: no response from agent Mar 11 18:58:05 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status... Mar 11 18:58:05 raspberrypi sudo[566]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s @1710219476 Mar 11 18:58:05 raspberrypi sudo[566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) ## Last log before startup schedule Mar 12 04:57:56 raspberrypi sudo[566]: pam_unix(sudo:session): session closed for user root Mar 12 04:57:56 raspberrypi wittypi[347]: Done :-) Mar 12 04:57:56 raspberrypi wittypi[347]: Firmware ID: 0x26 Mar 12 04:57:56 raspberrypi wittypi[347]: Firmware Revison: 0x05 Mar 12 04:57:58 raspberrypi wittypi[347]: Current Vin=13.25V, Vout=5.15V, Iout=0.08A Mar 12 04:58:01 raspberrypi wittypi[347]: System starts up because scheduled startup is due. Mar 12 04:58:11 raspberrypi wittypi[347]: Send out the SYS_UP signal via GPIO-17 pin. [...]
But the log says the system started up because the scheduled startup is due. That means Witty Pi's firmware previously emulated this button tap and wrote the reason code to register accordingly.
Mar 12 04:58:01 raspberrypi wittypi[347]: System starts up because scheduled startup is due.
Okay I think we found the reason for this.
As the MPPT Solar Driver is unable to limit its output to 14,5V, the LiFePo4 BSM cuts everything whenever the Solar Driver gives +15V. This happens whenever sky clears fast. So everything looses power.
As we have limited space in our case and have to find a solution for the current setup we thought about another battery to buffer input power for a minute or so.
Is there something something you can recommend for this case? 🙂
@mmoollllee maybe you can use another DC/DC between the MPPT Solar Driver and the BSM? There are some DC/DC converters have very good efficiency, especially when the input/output voltage difference is rather small.