Hello 🙂
We got a WittyPi with a Zero W and do experience the following issue:
Config:
6. Schedule Script: BEGIN 2015-08-03 06:00:00 END 2025-07-31 23:59:59 ON H14 OFF H10 7. Set low voltage threshold [11.5V] 8. Set recovery voltage threshold [11.7V] 9. Set over temperature action [T>60°C ➔ Shutdown]
Produced this log:
[2024-01-07 18:59:52] Shutting down system because scheduled shutdown is due. [2024-01-07 18:59:52] Halting all processes and then shutdown Raspberry Pi... [xxxx-xx-xx xx:xx:xx] Witty Pi daemon (v4.13) is started. [xxxx-xx-xx xx:xx:xx] Running on Raspberry Pi Zero W Rev 1.1 [xxxx-xx-xx xx:xx:xx] Seems RTC has good time, write RTC time into system [xxxx-xx-xx xx:xx:xx] Writing RTC time to system... [2024-01-08 05:01:07] Done :-) [2024-01-08 05:01:07] Firmware ID: 0x26 [2024-01-08 05:01:08] Firmware Revison: 0x05 [2024-01-08 05:01:11] Current Vin=13.25V, Vout=5.08V, Iout=0.17A [2024-01-08 05:01:14] System starts up because scheduled startup is due. [2024-01-08 05:01:24] Send out the SYS_UP signal via GPIO-17 pin. [2024-01-08 05:01:27] Pending for incoming shutdown command... [2024-01-08 05:02:01] Schedule next shutdown at: 2024-01-08 19:00:00 [2024-01-08 05:02:06] Schedule next startup at: 2024-01-09 05:00:00
Checking the RPi on 2024-01-08 11:34:00 its powerd off! After manual startup there is only this information in the wittyPi script:
[xxxx-xx-xx xx:xx:xx] Witty Pi daemon (v4.13) is started. [xxxx-xx-xx xx:xx:xx] Running on Raspberry Pi Zero W Rev 1.1 [xxxx-xx-xx xx:xx:xx] Seems RTC has good time, write RTC time into system [xxxx-xx-xx xx:xx:xx] Writing RTC time to system... [2024-01-08 11:34:14] Done :-) [2024-01-08 11:34:14] Firmware ID: 0x26 [2024-01-08 11:34:14] Firmware Revison: 0x05 [2024-01-08 11:34:17] Current Vin=13.13V, Vout=5.15V, Iout=0.08A [2024-01-08 11:34:19] System starts up because the button is clicked. [2024-01-08 11:34:28] Send out the SYS_UP signal via GPIO-17 pin. [2024-01-08 11:34:31] Pending for incoming shutdown command... [2024-01-08 11:34:58] Schedule next shutdown at: 2024-01-08 19:00:00 [2024-01-08 11:35:01] Schedule next startup at: 2024-01-09 05:00:00
Any tipps where it shuts down and how to resolve it?
@mmoollllee Please provide the log between [2024-01-08 05:02:06] and [2024-01-08 11:34:14], usually the software will log the reason for shutting down the Pi.
It may not be relavent but you are setting the low voltage threshold and recovery voltage threshold too close. Only 0.2V difference means your Pi most probably will be turned on again immediately after being shut down due to low voltage. I would suggest to set the recovery voltage threshold to at least 12.5V.
There is no log in between!
Here is the last lines from
journalctl -r
before RPi is gone again:
Jan 11 06:01:16 raspberrypi su[612]: pam_unix(su:session): session opened for user www-data(uid=33) by (uid=0) Jan 11 06:01:16 raspberrypi su[612]: (to www-data) root on none Jan 11 06:01:16 raspberrypi sudo[608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 06:01:16 raspberrypi sudo[608]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s @1704987017 Jan 11 06:01:16 raspberrypi pipewire-media-session[603]: could not set nice-level to -11: Permission denied Jan 11 06:01:15 raspberrypi sudo[551]: pam_unix(sudo:session): session closed for user root Jan 11 06:01:15 raspberrypi systemd[1]: Started Light Display Manager. Jan 11 06:01:15 raspberrypi systemd-timedated[554]: Set NTP to disabled. Jan 11 06:01:15 raspberrypi pipewire[562]: Failed to receive portal pid: org.freedesktop.DBus.Error.NameHasNoOwner: Could not get PID of name 'org.freedesktop.portal.Desktop': no such name Jan 11 06:01:15 raspberrypi pipewire[562]: could not make thread realtime: Permission denied Jan 11 06:01:15 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 142 (plymouthd). Jan 11 06:01:15 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 142 (plymouthd). Jan 11 06:01:15 raspberrypi kernel: vc4-drm soc:gpu: [drm] Cannot find any crtc or sizes Jan 11 06:01:15 raspberrypi kernel: vc4-drm soc:gpu: [drm] User-defined mode not supported: "1920x1080": 60 173106 1920 2048 2248 2576 1080 1083 1088 1120 0x20 0x6 Jan 11 06:01:15 raspberrypi rtkit-daemon[566]: Supervising 0 threads of 0 processes of 1 users. Jan 11 06:01:15 raspberrypi rtkit-daemon[566]: Supervising 0 threads of 0 processes of 1 users. Jan 11 06:01:15 raspberrypi systemd[444]: Started D-Bus User Message Bus. Jan 11 06:01:15 raspberrypi kernel: [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0 Jan 11 06:01:14 raspberrypi pipewire[562]: could not set nice-level to -11: Permission denied Jan 11 06:01:14 raspberrypi systemd[1]: Started Time & Date Service. Jan 11 06:01:14 raspberrypi kernel: vc4-drm soc:gpu: bound 20c00000.v3d (ops vc4_v3d_ops [vc4]) Jan 11 06:01:14 raspberrypi kernel: vc4-drm soc:gpu: bound 20807000.pixelvalve (ops vc4_crtc_ops [vc4]) Jan 11 06:01:14 raspberrypi kernel: vc4-drm soc:gpu: bound 20207000.pixelvalve (ops vc4_crtc_ops [vc4]) Jan 11 06:01:14 raspberrypi dbus-daemon[253]: [system] Successfully activated service 'org.freedesktop.timedate1' Jan 11 06:01:14 raspberrypi mtp-probe[581]: bus: 1, device: 3 was not an MTP device Jan 11 06:01:14 raspberrypi kernel: vc4-drm soc:gpu: bound 20206000.pixelvalve (ops vc4_crtc_ops [vc4]) Jan 11 06:01:14 raspberrypi kernel: vc4-drm soc:gpu: bound 20004000.txp (ops vc4_txp_ops [vc4]) Jan 11 06:01:14 raspberrypi kernel: vc4-drm soc:gpu: bound 20902000.hdmi (ops vc4_hdmi_ops [vc4]) Jan 11 06:01:14 raspberrypi mtp-probe[581]: checking bus 1, device 3: "/sys/devices/platform/soc/20980000.usb/usb1/1-1" Jan 11 06:01:14 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status... Jan 11 06:01:13 raspberrypi systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Jan 11 06:01:13 raspberrypi kernel: input: vc4-hdmi as /devices/platform/soc/20902000.hdmi/rc/rc0/input0 Jan 11 06:01:13 raspberrypi kernel: rc rc0: vc4-hdmi as /devices/platform/soc/20902000.hdmi/rc/rc0 Jan 11 06:01:13 raspberrypi kernel: Registered IR keymap rc-cec Jan 11 06:01:13 raspberrypi kernel: [drm] forcing HDMI-A-1 connector on Jan 11 06:01:13 raspberrypi kernel: vc4-drm soc:gpu: bound 20400000.hvs (ops vc4_hvs_ops [vc4]) Jan 11 06:01:13 raspberrypi kernel: Console: switching to colour dummy device 80x30 Jan 11 06:01:12 raspberrypi rtkit-daemon[566]: Watchdog thread running. Jan 11 06:01:12 raspberrypi rtkit-daemon[566]: Canary thread running. Jan 11 06:01:12 raspberrypi rtkit-daemon[566]: Running. Jan 11 06:01:12 raspberrypi rtkit-daemon[566]: Successfully limited resources. Jan 11 06:01:12 raspberrypi systemd[1]: Started RealtimeKit Scheduling Policy Service. Jan 11 06:01:12 raspberrypi rtkit-daemon[566]: Successfully dropped privileges. Jan 11 06:01:12 raspberrypi rtkit-daemon[566]: Successfully called chroot. Jan 11 06:01:12 raspberrypi dbus-daemon[253]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Jan 11 06:01:12 raspberrypi meyectl[264]: INFO: hello! this is motionEye server 0.42.1 Jan 11 06:01:11 raspberrypi systemd[1]: Starting RealtimeKit Scheduling Policy Service... Jan 11 06:01:11 raspberrypi su[421]: pam_unix(su:session): session closed for user www-data Jan 11 06:01:11 raspberrypi dbus-daemon[253]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.16' (uid=33 pid=562 comm="/usr/bin/pipewi> Jan 11 06:01:11 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 Jan 11 06:01:11 raspberrypi systemd[444]: Starting Sound Service... Jan 11 06:01:11 raspberrypi kernel: usbcore: registered new interface driver brcmfmac Jan 11 06:01:11 raspberrypi kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1 Jan 11 06:01:11 raspberrypi systemd[1]: Started Session c1 of user www-data. Jan 11 06:01:11 raspberrypi systemd[444]: Started Multimedia Service. Jan 11 06:01:11 raspberrypi systemd[1]: Started User Manager for UID 33. Jan 11 06:01:11 raspberrypi systemd[444]: Reached target Basic System. Jan 11 06:01:11 raspberrypi systemd[444]: Reached target Sockets. Jan 11 06:01:11 raspberrypi systemd[444]: Listening on D-Bus User Message Bus Socket. Jan 11 06:01:10 raspberrypi systemd[444]: Listening on Sound System. Jan 11 06:01:10 raspberrypi systemd[444]: Listening on debconf communication socket. Jan 11 06:01:10 raspberrypi kernel: brcmfmac: F1 signature read @0x18000000=0x1541a9a6 Jan 11 06:01:10 raspberrypi systemd[444]: Listening on Multimedia System. Jan 11 06:01:10 raspberrypi systemd[444]: Listening on GnuPG cryptographic agent and passphrase cache. Jan 11 06:01:10 raspberrypi systemd[444]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Jan 11 06:01:10 raspberrypi systemd[444]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Jan 11 06:01:10 raspberrypi systemd[444]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Jan 11 06:01:10 raspberrypi systemd[444]: Listening on GnuPG network certificate management daemon. Jan 11 06:01:10 raspberrypi systemd[444]: Starting D-Bus User Message Bus Socket. Jan 11 06:01:10 raspberrypi systemd[444]: Reached target Timers. Jan 11 06:01:10 raspberrypi systemd[444]: Reached target Paths.
I've set recovery voltage threshold to 12.5V now. I'll know tomorrow if it does change something.
Ohh I think I found the reason because the RPi didn't wake up from
sudo reboot
I forgot to disable a old crontab that made sure to reboot the RPi every morning.. Must have been the reason.
I'll try without again!
Anyway: Is there a way to make sure it turns on again after crashes or manual reboot?
@mmoollllee Usually a reboot should not cause a problem like this. In order to wake the pi up, two conditions need to be satisfied:
- The next startup time has been properly configured (either by schedule script or manually).
- The Pi is not powered (Witty Pi white LED blinks) when the startup time is due.
Hmm with the mentioned configuration If I do
sudo reboot
at time: 13:00
-> The RPi does shutdown but not boot again!
Powerconnection is constant.
I'll have to wait for the next scheduled startup in order to access it again without pressing the button. Can this be changed?
@mmoollllee reboot is a combination of shutdown and startup. The firmware already has some special handling for reboot, but still if the startup doesn't happen soon enough (TXD voltage goes high fast enogh), it will be considered as a shutdown instead of reboot.
Prolonging the delay for power cut (up to 25 seconds) may workaroudn such issue.
You may also want to make sure the TXD pin connection is good.
I just set the power cut delay to 25 seconds but manual reboot still fails...
If reboot is handled by measuring power usage, maybe the D-Link USB Dongle (keeps running while reboot happens until power cut) could be the reason for malfunction?
@mmoollllee reboot is not handled by measuring power usage. TXD voltage is the only thing that lets the MCU know if the system is up.
I would suggest to monitor the voltatge on TXD pin during the reboot, and measure the time that needed for a full reboot (withtout Witty Pi). If 25 seconds are still not enough to start the Pi again, there must be something happening.
I monitored TxD Pin Voltage which is at ~3V with a 1 second drop to 0V after ~20 seconds.
So here is what's happening when doing the reboot:
- I do sudo reboot, RPi LED is flickering for about 20 Seconds
- LED turns of for about 1 second
- LED returns flickering for another 25 seconds
- LED turns of and WittyPi LED starts blinking
Essentials from journalctl, showing that booting stops at 18:46:45 -> Pressing Power Button -> Next log from 18:51:26
[...] Jan 23 18:51:26 raspberrypi wittypi[341]: Done :-) Jan 23 18:51:26 raspberrypi sudo[609]: pam_unix(sudo:session): session closed for user root Jan 23 18:46:45 raspberrypi sudo[609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 23 18:46:44 raspberrypi sudo[609]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s @1706032286 Jan 23 18:46:44 raspberrypi systemd[1]: Started Light Display Manager. [...] Jan 23 18:46:32 raspberrypi wittypi[341]: Witty Pi daemon (v4.13) is started. [...] Jan 23 18:46:11 raspberrypi wittypi[336]: Starting Witty Pi 4 Daemon... [...] Jan 23 18:45:45 raspberrypi kernel: Booting Linux on physical CPU 0x0 -- Boot a08807557efb44c7b318afd8ffc09110 -- Jan 23 18:45:43 raspberrypi systemd-shutdown[1]: Syncing filesystems and block devices. Jan 23 18:45:43 raspberrypi systemd[1]: Failed to set timeout to 600s: Invalid argument Jan 23 18:45:43 raspberrypi systemd[1]: Using hardware watchdog 'Broadcom BCM2835 Watchdog timer', version 0, device /dev/watchdog Jan 23 18:45:43 raspberrypi systemd[1]: Shutting down. Jan 23 18:45:43 raspberrypi systemd[1]: Reached target Reboot. [...] Jan 23 18:45:27 raspberrypi sudo[3110]: mg : TTY=pts/0 ; PWD=/home/mg ; USER=root ; COMMAND=/usr/sbin/reboot
If I understand correctly, your Pi took about 20 seconds to shutdown. That's really not normal, usually the shutdown process should finish with just a few seconds. You need to check what was blocking the shutdown procedure.
I do sudo reboot, RPi LED is flickering for about 20 Seconds
True... I had a lot of other software running on my dev device...
Works now!