Logik mit crontab sunset+35m wird nach einmaliger Ausführung erst Wochen später wieder eingeplant

[wi26]

Sorry, war ein paar Tage offline.

bmx
> Ich habe nun mit Deiner Location (Funkturm Berlin?) das in SHNG v1.12.1 nachzustellen.
ich wusste es ist sinnvoll Fake Koordinaten zu nutzen, falls ich die mal rausrücken muss ;-)
im übrigen funktioniert es bei mir am ersten Tag auch so wie bei dir. du hast das debugging aber nicht aktiv bzw nicht mitgeschickt. interessant ist welchen Zeitwert der Folgeaufruf bekommt.


ich habe auch nochmal nachgeschaut. Mein ephem Package wurde nicht aktualisiert. Um solche Einflüsse zu vermeiden, habe ich alle zusätzlichen Pakete in eine virtuelle Umgebung gebracht.

/usr/local/smarthomeNG/venv/lib/python3.12/site-packages/ephem-4.1.5

aber, am 30.5. wurde das python3.12 package des Systems aktualisiert. Das passt ziemlich gut in das Muster.

$ grep python312 /var/log/pacman.log
[2025-05-30T11:53:27+0200] [ALPM] installed python312 (3.12.10-1)​

ich habe versehentlich den orb debug rausgefiltert. hier der erste Durchlauf nach einem Neustart:

2026-06-22 22:08:51 DEBUG logics.shutter_down_sunset Getriggert durch: {'by': 'Scheduler', 'source': 'cron', 'source_details': 'sunset+35m', 'dest': None, 'value': 'sunset'}
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-06-22 22:08:52.239281+02:00 will be 2026-06-22 20:08:51.363883+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-06-23 00:00:00+02:00 will be 2026-06-22 20:08:51.313065+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-06-24 00:00:00+02:00 will be 2026-06-23 20:08:57.972499+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-06-25 00:00:00+02:00 will be 2026-06-24 20:09:01.335644+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-06-26 00:00:00+02:00 will be 2026-06-25 20:09:01.396209+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-06-27 00:00:00+02:00 will be 2026-06-26 20:08:58.151815+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-06-28 00:00:00+02:00 will be 2026-06-27 20:08:51.603760+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-06-29 00:00:00+02:00 will be 2026-06-28 20:08:41.756771+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-06-30 00:00:00+02:00 will be 2026-06-29 20:08:28.618842+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-01 00:00:00+02:00 will be 2026-06-30 20:08:12.098254+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-02 00:00:00+02:00 will be 2026-07-01 20:07:52.401710+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-03 00:00:00+02:00 will be 2026-07-02 20:07:29.459868+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-04 00:00:00+02:00 will be 2026-07-03 20:07:03.293490+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-05 00:00:00+02:00 will be 2026-07-04 20:06:33.926183+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-06 00:00:00+02:00 will be 2026-07-05 20:06:01.384292+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-07 00:00:00+02:00 will be 2026-07-06 20:05:25.696729+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-08 00:00:00+02:00 will be 2026-07-07 20:04:46.894896+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-09 00:00:00+02:00 will be 2026-07-08 20:04:05.012582+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-10 00:00:00+02:00 will be 2026-07-09 20:03:20.085874+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-11 00:00:00+02:00 will be 2026-07-10 20:02:32.240172+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-12 00:00:00+02:00 will be 2026-07-11 20:01:41.315776+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-13 00:00:00+02:00 will be 2026-07-12 20:00:47.461620+00:00
2026-06-22 22:08:52 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=35, center=True, dt=2026-07-14 00:00:00+02:00 will be 2026-07-14 19:58:51.139826+00:00
2026-06-22 22:08:52 DEBUG lib.scheduler logics.shutter_down_sunset next time: 2026-07-14 21:58:51.139826+02:00

ich finde den loop nicht, der Orb.set() so oft aufrufen kann.

[bmx]

Interessanterweise ist der erste Wert mit +02:00 und alle weiteren ohne. Das spricht dafür das dort ein Bug drin ist der mit den Zeitzonenzeitverschiebung in Korrelation steht. @Morg42 hat einiges gemacht und PR gestellt. Vielleicht kann das damit bereits behoben werden. Allerdings komme ich jetzt da zeitlich nicht wirklich ran um mir eine Testumgebung dafür aufzusetzen.

[Morg]

Da die UTC-Verschiebungen tatsächliche Bugs waren und die Tests dazu passen, habe ich das gemergt, könnt ihr einfach in develop testen.

Die zusätzliche Möglichkeit, von pyephem auf skyfield zu wechseln, habe ich im zweiten PR beschrieben.

[bmx]

Ich versuche mir das bei nächster Gelegenheit mal zu ziehen. wi26 hast Du die Möglichkeit Dein Setting mit der aktuellen develop zu testen?

[wi26]

der test steht für das wochenende auf der todo liste.

btw: wvhn wollte wisssen, ob sich das verhalten mit "sunset+15m" aendert: ja!

2026-06-25 21:49:01 DEBUG logics.shutter_down_sunset Getriggert durch: {'by': 'Scheduler', 'source': 'cron', 'source_details': 'sunset+15m', 'dest': None, 'value': 'sunset'}
2026-06-25 21:49:02 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=15, center=True, dt=2026-06-25 21:49:02.309013+02:00 will be 2026-06-25 19:49:01.386018+00:00
2026-06-25 21:49:02 DEBUG lib.orb ephem: next_setting for sun with doff=0.0, moff=15, center=True, dt=2026-06-26 00:00:00+02:00 will be 2026-06-26 19:48:58.120932+00:00
2026-06-25 21:49:02 DEBUG lib.scheduler logics.shutter_down_sunset next time: 2026-06-26 21:48:58.120932+02:00​

[wvhn]

btw: wvhn wollte wisssen, ob sich das verhalten mit "sunset+15m" aendert: ja!

Ich hatte den Verdacht, dass die Zeitzone falsch verwendet wird, was sich ja auch bestätigt hat. Wenn nochmal 2 Stunden (die Differenz zu UTC) auf den Sonnenuntergang addiert werden, kann es in der Nähe des 21.6. dazu kommen, dass mit dem Offset von 35 min der nächste geplante Ausführungszeitpunkt über Mitternacht hinaus rutscht. Vermutlich wird dann weiter gesucht, bis nach dem 21.6. wieder ein Sonnenuntergang passt. Daher der Vorschlag, es mal mit kleinerem Offset zu versuchen.

Allerdings müsste man für den Test das Systemdatum auf z.B. den 18.6. zurück setzen, um das nachzuweisen. Das wäre jetzt akademisch, aber ich würde empfehlen, den Code im develop auch mal mit einem Datum kurz vor dem 21.6. zu testen.

Gruß
Wolfram

[wvhn]

Moin Morg Sebastian,

ich wollte mal skyfield testen. Habe den aktuellen develop branch ausgecheckt, den PR#802 in einen neuen lokalen branch gemerged und dorthin gewechselt:

git pull origin pull/802/head:skyfieldtest
git checkout skyfieldtest

Habe ein paar Dateien aus develop und dem PR geprüft. Sie sind vorhanden und auf dem richtigen Stand. Dann habe ich das Tool fetch_skyfield_data ausgeführt. Dieses installiert mir die Pakete numpy v2.4.6, jplephem v2.24, sgp4 v2.26 und skyfield v1.54. Im Admin-Interface von shNG werden diese als installiert angezeigt, so dass ich davon ausgehe, dass sie im richtigen venv installiert wurden.
Das Tool wird dann mit folgender Meldung beendet:

lib.orb's skyfield backend is still not available after installing skyfield - see the error above.

Es wird aber kein anderer Fehler angezeigt.
OS: Raspbian bookworm
Python v3.11.2

Was mache ich falsch?

Danke und Gruß
Wolfram

[Morg]

Muss ich reinschauen, möchte im Moment mein momentanes Setup aber nicht umbauen. Hat das etwas Zeit?

[wvhn]

ja, hat Zeit. Dann teste ich erstmal develop ohne skyfield. Ich dachte nur, DIr fällt vielleicht gleich etwas dazu ein.

Soweit ich das beurteilen kann, wird das Array "_BACKENDS" aus lib.orb importiert und die Meldung wird ausgegeben, wenn der der Schlüssel "skyfield" nicht vorhanden ist. Der wird in lib.orb nur gesetzt, wenn skyfield.api.Loader gefunden wird. Da scheint es zu haken.

Gruß
Wolfram

EDIT: hab jetzt mal den Import manuell in der Python Shell eingegeben. Fehlermeldung:

Original error was: libopenblas.so.0: cannot open shared object file: No such file or directory

Ich schau mal weiter und berichte ...

[wvhn]

sudo apt-get install libopenblas-dev​

löst das Problem und die skyfield-Daten werden heruntergeladen.
Dann in der smarthome.yaml "orb_backend: skyfield-cached" gesetzt. Jetzt Erscheinen für die UZSU-Einträge:

2026-06-28  12:37:23 ERROR    lib.item.item       Item eg.wohnzimmer.licht.haupt.uzsu: problem creating: ufunc 'divide' not supported for the input types, and the inputs could not be safely coerced to any supported types according to the casting rule ''safe''
> Traceback (most recent call last):
>   File "/usr/local/smarthome/lib/item/item.py", line 600, in __init__
>     child = Item(smarthome, self, child_path, value)
>             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/lib/item/item.py", line 688, in __init__
>     update = plugin.parse_item(self)
>              ^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/plugins/uzsu/__init__.py", line 560, in parse_item
>     self._update_item(item,  'init')
>   File "/usr/local/smarthome/plugins/uzsu/__init__.py", line 660, in _update_item
>     success = self._get_sun4week(item, caller="_update_item")
>               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/plugins/uzsu/__init__.py", line 1319, in _get_sun4week
>     mysunrise = self._sun(day.astimezone(self._timezone), "sunrise", "next")
>                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/plugins/uzsu/__init__.py", line 1503, in _sun
>     next_time = self._sh.sun.rise(doff, moff, dt=dt)
>                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/lib/orb.py", line 760, in rise
>     next_rising = self._backend.next_rising(self.lon, self.lat, self.elev, self.orb, date_utc, doff, center)
>                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/lib/orb.py", line 479, in next_rising
>     result = self._lookup(
>              ^^^^^^^^^^^^^
>   File "/usr/local/smarthome/lib/orb.py", line 465, in _lookup
>     _start, end, entries = refill(date_utc)
>                            ^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/lib/orb.py", line 483, in <lambda>
>     lambda start: self._refill_riseset(lon, lat, elev, body, doff, skyfield_almanac.find_risings, start),
>                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/lib/orb.py", line 425, in _refill_riseset
>     observer = self._observer(lon, lat, elev)
>                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/lib/orb.py", line 284, in _observer
>     topos = wgs84.latlon(latitude_degrees=lat, longitude_degrees=lon, elevation_m=elev or 0)
>             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/venvs/py_shng/lib/python3.11/site-packages/skyfield/toposlib.py", line 173, in latlon
>     latitude = Angle(degrees=latitude_degrees)
>                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   File "/usr/local/smarthome/venvs/py_shng/lib/python3.11/site-packages/skyfield/units.py", line 283, in __init__
>     self.radians = degrees / 360.0 * tau
>                    ~~~~~~~~^~~~~~~
> TypeError: ufunc 'divide' not supported for the input types, and the inputs could not be safely coerced to any supported types according to the casting rule ''safe''
​

Der Fehler bleibt bestehen, wenn ich die Plugins auf develop aktualisiere und den PR zum UZSU-Plugin einspiele.

Wenn ich "orb_backend: ephem" einstelle, läuft die Initialisierung ohne Fehler durch.

Gruß
Wolfram

[Morg]

Mea culpa... hat mir doch keine Ruhe gelassen. Bei einem der letzten Updates ist der Startup von shng durcheinander gekommen, und shng startet nicht, ohne vorher Pakete von Hand zu installieren, was natürlich Blödsinn ist. Ich pushe einen Fix in develop (und werde wohl noch ein Release machen müssen), aber probier es nochmal mit dem - jetzt - aktuellen develop.

Wenn es das nicht ist, muss ich noch weiter suchen, aber bei mir geht es ohne Fehler.