I’ve had to add .txt to get the forum to accept it - just remove that extension after downloading, it’s really a JAR file.
When it comes to replacing the existing version of the binding, I think you need to use the Karaf console. Assuming that you know how to open that, you need to stop the existing bundle/binding. To do that, you need to find the ID:
list | grep -i astro
It should produce something like this:
252 | Active | 80 | 4.2.3 x openHAB Add-ons :: Bundles :: Astro Binding
This means that the ID of the bundle is 252. Yours will be different, but take note of the ID - this is the ID of the original binding.
Then, stop the existing binding with:
bundle:stop <bundle ID>
While keeping the Karaf console open, drop this JAR into your addons folder. A notice that a new bundle has been found, with it’s assigned ID, should appear. Once that has happened, you just need to start the “replacement bunde” with:
bundle:start <bundle ID>
To restore the system to what it was, stop the “replacement bundle” and start the original. You can then remove/delete the file from addons.
I’ve tweaked the logging and made some extra checks around this, so let’s see what it does the next time. Btw, I found that the date formatter was actually only used for logging, so I’ve tweaked the format to include milliseconds.
I hope that it’s your new version now - though I actually doubt it, because the log entries that it generated upon start don’t show milliseconds in the time output:
2026-01-03 19:39:48.005 [DEBUG] [enhab.binding.astro.internal.job.Job] - Not scheduling Event job astro:sun:sun/rise#event/START since it’s in the past (S at Jan 03 08:25:22 CET 2026)
Ah, openhab.log said the following when I first copied the jar to the addons folder:
2026-01-03 19:30:05.572 [WARN ] [org.apache.felix.fileinstall ] - A bundle with the same symbolic name (org.openhab.binding.astro) and version (5.1.0) is already installed. Updating this bundle instead.
Yes, I wish it didn’t do that, but OK. That means that it was replaced with my bundle. The new one is my version, but maybe I did something wrong when backporting the log formatting - because the “Not scheduling” message itself is new in my version.
edit: Checked the code, and the formatter isn’t in use in that location. But, when they are actually scheduled, they should have milliseconds.
edit2: To get the old bundle back (if you wish to), you’ll probably just have to remove the file and then reinstall the binding from the UI. That should restore the original file. I had no idea that it would update the file, I should have given it a different version number, because I think it did the update because they matched.
Thank you very much. I was about to ask whether you could do that. I will need to focus my energy a bit more on my own projects again, now that the new year seriously starts. Therefore, while it’s definitely fun figuring out what exactly is going on here, I am not sure if I really want to own the issue for a bug that will very likely never even affect me, in a piece of software from which I will likely need to move away anyway.
Of course I’ll help with the early scheduling issue, though, as long as my support is useful. (And I also hope that I’ll finally figure out why some of my rules are still not triggering at all. Occasionally. Randomly.)
Here’s what the night brought with your modified version of Astro:
2026-01-04 00:00:31.007 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/rise#event/START in 30280777ms (at 2026-01-04T08:25:11.784) 2026-01-04 00:00:31.007 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/rise#event/END in 30523125ms (at 2026-01-04T08:29:14.132) 2026-01-04 00:00:31.007 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/set#event/START in 59806888ms (at 2026-01-04T16:37:17.895) 2026-01-04 00:00:31.007 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/set#event/END in 60049235ms (at 2026-01-04T16:41:20.242) 2026-01-04 00:00:31.007 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/noon#event/START in 45165006ms (at 2026-01-04T12:33:16.013) 2026-01-04 00:00:31.007 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/noon#event/END in 45225006ms (at 2026-01-04T12:34:16.013) 2026-01-04 00:00:31.007 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/night#event/START in 67095499ms (at 2026-01-04T18:38:46.506) 2026-01-04 00:00:31.007 [DEBUG] [enhab.binding.astro.internal.job.Job] - Not scheduling Event job astro:sun:sun/night#event/END since it’s at another date (Mon Jan 05 06:27:41 CET 2026) 2026-01-04 00:00:31.007 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/morningNight#event/END in 23234514ms (at 2026-01-04T06:27:45.521) 2026-01-04 00:00:31.007 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/astroDawn#event/START in 23234514ms (at 2026-01-04T06:27:45.521) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/astroDawn#event/END in 25569879ms (at 2026-01-04T07:06:40.887) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/nauticDawn#event/START in 25569879ms (at 2026-01-04T07:06:40.887) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/nauticDawn#event/END in 28021058ms (at 2026-01-04T07:47:32.066) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/civilDawn#event/START in 28021058ms (at 2026-01-04T07:47:32.066) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/civilDawn#event/END in 30280776ms (at 2026-01-04T08:25:11.784) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/astroDusk#event/START in 64760132ms (at 2026-01-04T17:59:51.140) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/astroDusk#event/END in 67095498ms (at 2026-01-04T18:38:46.506) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/nauticDusk#event/START in 62308953ms (at 2026-01-04T17:18:59.961) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/nauticDusk#event/END in 64760132ms (at 2026-01-04T17:59:51.140) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/civilDusk#event/START in 60049234ms (at 2026-01-04T16:41:20.242) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/civilDusk#event/END in 62308953ms (at 2026-01-04T17:18:59.961) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/eveningNight#event/START in 67095498ms (at 2026-01-04T18:38:46.506) 2026-01-04 00:00:31.008 [DEBUG] [enhab.binding.astro.internal.job.Job] - Not scheduling Event job astro:sun:sun/eveningNight#event/END since it’s at another date (Mon Jan 05 00:00:00 CET 2026) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/daylight#event/START in 30523124ms (at 2026-01-04T08:29:14.132) 2026-01-04 00:00:31.008 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Event job astro:sun:sun/daylight#event/END in 59806887ms (at 2026-01-04T16:37:17.895) 2026-01-04 00:00:31.009 [DEBUG] [enhab.binding.astro.internal.job.Job] - Not scheduling Event job astro:sun:sun/eclipse#event/TOTAL since it’s at another date (Wed Aug 12 19:47:20 CEST 2026) 2026-01-04 00:00:31.009 [DEBUG] [enhab.binding.astro.internal.job.Job] - Not scheduling Event job astro:sun:sun/eclipse#event/RING since it’s at another date (Tue Feb 17 13:13:56 CET 2026) 2026-01-04 00:00:31.009 [DEBUG] [enhab.binding.astro.internal.job.Job] - Not scheduling Event job astro:sun:sun/eclipse#event/PARTIAL since it’s at another date (Sun Jan 14 18:13:34 CET 2029) 2026-01-04 00:00:31.009 [DEBUG] [enhab.binding.astro.internal.job.Job] - Not scheduling Publish planet job astro:sun:sun since it’s at another date (Mon Jan 19 23:59:59 CET 2026) 2026-01-04 00:00:31.009 [DEBUG] [enhab.binding.astro.internal.job.Job] - Not scheduling Publish planet job astro:sun:sun since it’s at another date (Fri Mar 20 15:46:45 CET 2026) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/SUN_RISE in 30280775ms (at 2026-01-04T08:25:11.784) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/SUN_SET in 59806886ms (at 2026-01-04T16:37:17.895) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/NIGHT in 67095497ms (at 2026-01-04T18:38:46.506) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/DAYLIGHT in 30523123ms (at 2026-01-04T08:29:14.132) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/ASTRO_DAWN in 23234512ms (at 2026-01-04T06:27:45.521) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/NAUTIC_DAWN in 25569878ms (at 2026-01-04T07:06:40.887) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/CIVIL_DAWN in 28021057ms (at 2026-01-04T07:47:32.066) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/ASTRO_DUSK in 64760131ms (at 2026-01-04T17:59:51.140) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/NAUTIC_DUSK in 62308952ms (at 2026-01-04T17:18:59.961) 2026-01-04 00:00:31.009 [DEBUG] [o.internal.handler.AstroThingHandler] - Scheduled Sun phase job astro:sun:sun/CIVIL_DUSK in 60049233ms (at 2026-01-04T16:41:20.242)
Hold your breath: It’s scheduling at millisecond accuracy. The millisecond values are not aligned. The timestamps are not on full seconds. It silently discards the START of morningNight.
The triggers in events.log are likewise no longer on full seconds:
Are you saying that despite the “scheduling fix”, the rules still fail? Or is that a different issue, with no triggering at all?
It seems to me like the scheduling fix worked like it should. The enhanced logging didn’t hurt either, it’s a bit easier when you see the stuff that isn’t scheduled (and why), and when you see the milliseconds of the schedule. So, the big question, did this solve the problem with the rules? Do they now work as intended?
Sure, I can, if you seriously want to hear. Shall I?
It’s definitely become much better now, because a significant share of what I initially believed to be missing triggers was failed guards due to early triggering. Most of my logging in most rules was behind guards. But that definitely doesn’t explain everything that I have been seeing (or rather: not seeing) since the 5.1.0 update, because also things didn’t happen in (sometimes trivially simple) rules that don’t even check the current time at all. In one of my early posts in this thread, I quoted one of my rules which doesn’t have a guard, and I noticed it didn’t trigger. Other rules that also didn’t trigger wrote log entries right at the start, and I didn’t get these log entries for several days in a row. Then (without me intentionally changing anything even just vaguely related to that) it suddenly started working again. Currently my entire system makes the impression of being not very, let’s say, deterministic in its behavior.
So, there’s light and there’s shadow: Yes, it’s become much, much better. And I assume the problems that are left are not Astro problems. The problem with the problems that are left is that they appear to be nondeterministic. It seems to be hitting here and there, occasionally. Missing a rule trigger here of which I know that it must have happened now and then. Not updating a state here and there, but just sometimes. And I have no idea at all how I can systematically debug that, as long as I don’t manage to figure out a pattern.
Of course - I’m trying to fix bugs and annoyances here and there, and am interested to hear what bothers/frustrates people, both for general understanding, and because perhaps there is something I should focus on/try to find a solution to.
I want to know if I should consider this a success and try to get it merged into the Astro binding.
As to the more general triggering issues, I’m not sure that I know exactly where “this started” because this thread was started in 2021 and was about OH 3.1. So, while the subject is the same, I’m pretty sure that the reasons are not.
I’m pretty confident that all these things can be figured out, but some can be tricky to pin down, obviously, but we just have to try as best we can.
Generally, I don’t upgrade (any software) until I have a reason to. Too many bugs come with updates these days, things are rushed and not properly tested (because it’s deemed more important to have frequent updates than stable software). People often say that you should never upgrade to a new version until the first patch is out. There is some truth to that, although if everybody followed the advice, the first patch wouldn’t have the same value. Back when we could decide when to upgrade, I had my own rule that I never upgraded Windows version until service pack 2 was released - which usually meant well over a year since release. My point: if stability and predictability is important to you, don’t run among the first in the crowd - hang back and see how the front runners do.
If this is a general problem, it is very serious. I think we would have had more reports if that were the case though, but never say never. Some bindings can cause problems across the system, other times there case be hardware problems like defective RAM or a failing SD card. I actually had a lot of “strange behavior” in OH a couple of years back that almost drove me crazy, which all went away when I move to a new SD card. It was failing and led to subtle problems all over the place.
If the problem is with rules and triggering, I would enable DEBUG logging for org.openhab.core.automation for a while. It will shed more light into the rule engine and what it’s up to - if you’re lucky, it will give a very good hint, if not, it still may help “steer the focus” in the right direction.
And now the much more important, much shorter other answers:
A definite YES. I am 99% sure that the problems I still believe to see are unrelated, and that the Astro triggers now work as they did in previous OH versions, i.e., as they should (with possible rarer exceptions that are not related to early firing). In case it didn’t sound like this: A big, big “thank you”.
I guess there were such reports in the forum, for some past versions. I didn’t follow very thoroughly, but when I suffered I had the impression that I am not alone. I just had the impression that this is a clear case of “can’t be, works for me” when someone raises it.
Errrrr… yes. I might. But with the scale of my system, the amount of logging junk will be absolutely overwhelming. I am not sure if I will be able to spot the needle in that giant haystack. And I fear a smaller system with less events, less rules will simply not get that sort of hiccup often enough to not be dismissed as “happened once, never seen it again, who knows what went wrong” (that’s just guessing, though).
I have had issues with missing rule triggers in the past (but not reported in this thread, and not specifically in Astro). What I was referring to is when I joined the discussions in this thread a week ago ( Astro Binding Triggers Stop Working - #15 by bjscheue ). I was also seeing effects where I’d say “there should clearly have been a triggering rule, but it wasn’t” before and after upgrading my server hardware, and before and after OS upgrades, so I am pretty sure this is not (just) the underlying system.
Thanks, that’s what I needed to know, I’ll move on trying to get this into the binding then.
I get what you’re saying here - it can be frustrating, but I was thinking about if there was something new that broke in that regard in 5.1 in this situation. I have my suspicions that thread starvation can be the cause of at least a part of these issues more generally, and I have a potential solution for this that I need to get tested on a large installation
I get that, I didn’t know that the installation was that big. It is possible, although a bit more involved, to define multiple log files with different content (just like what is done for events), so you could theoretically define a separate log files for automation debugging, and when something odd happened (in the “normal log”) look it up there using the time stamp - or get somebody™ to try to help interpret the debug log.
The dismissive attitude is well known to me, and not something I appreciate either. I’d say that it’s a human trait, not OH specific, but it can be very demotivating. I think it’s often caused by those on the other end not knowing how to solve it, and instead of admitting that, tries to dismiss it while keeping their “pride” intact. I try to fight this whereever I come across it, but it sometimes feel like I’m fighting humanity itself
I’m a bit confused here now - are you saying that there’s an additional issue with Astro events that is new in 5.1, in addition to what we have been addressing here?
After reading the issue, I think there are several things in play there too, but errors of the type:
2025-12-27 14:55:11.577 [ERROR] [o.internal.handler.AstroThingHandler] - Can't update state for channel astro:sun:sun:civilDusk#event : org.openhab.binding.astro.internal.model.Range.getEvent()
java.lang.NoSuchMethodException: org.openhab.binding.astro.internal.model.Range.getEvent()
..I know what’s causing, and I think I can fix it if I can figure out exactly what event/circumstance produces this. In short, the binding uses something called refection (out of laziness I assume) so that events can be handled more generally instead of individually for each type (in the code). But, the drawback of this is that static code analysis/the compiler can’t see if there are missing methods, and will just accept the code where it would otherwise have produced an error. These errors then show up during runtime instead.
The “real fix” is to get rid of the reflection, making this situation impossible. But, that’s quite a lot of restructuring with a relatively high likelihood of causing new bugs that must be tracked down and solved. The other solution is simply to track down those missing methods and create them where they are needed.
Well, I might be convinced to provide a large installation for testing. And I trust in your judgment whether it’s safe enough (or at least easily reversible).
No. I’m saying that right now I find it very hard to tell what it is and what it isn’t:
I am very (>99%) sure that I saw rules not trigger from time to time in the past. This was not specific to Astro. There were times when this seemed to happen rather frequently, and times where it (almost) never happened. It’s not always possible to just become reasonably confident if it’s something very occasional. So I found it quite hard to start reasonable debugging while I didn’t see any sort of pattern.
I am rather (>90%) confident that I also saw such cases recently, after the 5.1 upgrade.
However, it blurs with the early trigger thing. First I noticed that many, many rules didn’t seem to trigger. I started tracking it down, and found the early Astro trigger problem. This definitely explains a large share of the rule executions that I was missing. I don’t think it explains all of them, though - simply because the set of rules with missing triggers that I narrowed down initially includes rules which don’t use guards.
What I can not say with reasonable certainly at this point is how often it happened, whether something else was at play, whether it’s specific to Astro, or whether the “rest” of what I was missing shows some other pattern.
Therefore, at this point, I think it doesn’t make sense to waste anyone’s time on hunting down problems based on so little and unclear information. It makes more sense to wait, watch, and become active if I get into a phase where triggers appear to be missing again.
That’s great. It shouldn’t be much risk at all, the worst that can happen is probably that things don’t do what they should and that the original bundle must be restored before they start working. It doesn’t change anything except how threads are managed, it does nothing to change the behavior otherwise. I have tested it myself without any issues. What I mostly want to “test” is how much of an impact this has on a large system, how much of a difference it makes. It would also be nice to capture some “profiling data” with and without the modification. I don’t know if you have any such tools available already? I’m thinking of number of threads, memory, CPU utilization etc.
I’ll have to build a bundle for 5.1 and get back to you.
That sounds like a good plan. We humans are limited in our ability to manage chaos, we must try to separate things before we can really deal with them.
By the way, the fix is making its way into the binding, and is most likely going to be backported to 5.1 so that it will be included in 5.1.1:
The .txt extension is just there because the forum don’t accept JAR files - just rename it, it’s really a JAR file.
This bundle it the “central” bundle of OH Core. Don’t let that scare you, but it probably means that replacing it will take some time, since as good as any other bundle depends on it, they will all have to be restarted. This is done automatically, but expect it to take significantly longer than replacing a binding bundle.
I’ve found a little procedure to make it easy to reinstall the original, should it be necessary (this isn’t an add-on, so it can’t simply be reinstalled from the UI). I’m sure there’s a simpler way, but this should work. First, you need to find the bundle ID of the existing bundle:
In my example, “156” is the ID we’re after. Once you have that, run:
bundle:list -l 156
..(obviously with your ID instead of 156) which should result in something like this:
> 156 │ Active │ 80 │ 5.1.0.202512050249 │ mvn:org.openhab.core.bundles/org.openhab.core/5.1.0-SNAPSHOT
The interesting part is in the last column, the mvn:org.openhab.core.bundles/org.openhab.core/5.1.0-SNAPSHOT in my example (yours will probably be mvn:org.openhab.core.bundles/org.openhab.core/5.1.0). Store this address somewhere (copy/paste it) so that you have it when you need to go back to the original.
The original bundle can then be installed at any time using bundle:install mvn:org.openhab.core.bundles/org.openhab.core/5.1.0 or bundle:update mvn:org.openhab.core.bundles/org.openhab.core/5.1.0 depending on whether the bundle is currently installed or not.
Once you have secured the address to the original bundle, I think you can just drop “my” bundle in the addons folder, and it will probably replace the existing one automatically, restarting all the others etc. and then come online again.
Okay, I’ll do that. I don’t know if I get around to do it today, though. The week turns out to be very busy. If not today, then at the latest on the coming weekend.
Any specific wishes/preferences? sysstat/sar would be easy, I could also send basic system utilization statistics a few days back. If it helps, I can add a cronjob that periodically dumps the output of pidstat -t for OH’s PID/TGID into a file, too.
The most important thing for me is to see what it does to the number of threads and memory consumption. So, anything that captures that “will do” essentially.
If you want to spoil me, you could create (before and after) Java Flight Recorder files, which I can analyze in JDK Mission Control.
You “record” the these using jcmd. There are many options for jcmd, but the gist is:
Find the OH PID:
sudo ps ax | grep java
Once you know the PID, do:
sudo jcmd <PID> JFR.start name=<some name>
You can check ongoing sessions with
sudo jcmd <PID> JFR.check
Once you feel that you’re done, stop the recording with:
sudo jcmd <PID> JFR.stop name=<the same name> filename=<output file>.jfr
These files are too large for the forum, so they must be dumped on some “transfer”/upload site.
This will allow quite detailed information about what’s going on, most of which are more detailed than I actually need. But, some of it might be nice. Again, the number of running threads and heap use are the core pieces of information that I want to compare, so they alone will do - but averages are more useful than snapshots from some arbitrary point in time.
That’s not needed, and the resulting data would be huge too. Give it anywhere from 5 to 15 minutes, depending on how patient you are, and try to make sure that OH is in a relatively “normal” state while recording. By default (unless you specify different), jcmd limits the file size to 250 MB, and I don’t know how long it takes to reach that level. When I did a test recording on my much smaller production system, a couple of minutes or so resulted in a file slightly about 1 MB. If the files are too big, they will just be a lot of hassle to transfer and analyze anyway, so I don’t need them to be anywhere near 250 MB.
