Timers in my log
-
OK. If it is 21058, please open a PR. Then stop Reactor, clear the log files (delete), and then start Reactor. Let it run for 15-20 seconds, and then stop it again. Gather the log file, compress, and email as attachment to the address in the Support section of the About tab.
-
Oh, and can you screen shot a couple of those rules as well? If you click on the rule name in the Rule Sets tab, it will open rule status and show you the ID for the rule. Just match that up to two or three of logged rules.
-
Ok, I have reported it. Sent you an e-mail with the logs and left some screen shots in MBT. But every rule works fine but my logs ar flooded
You said that you left some "hooks" in the earlier problem with rules spanning over mid-night. Could it be related? -
Ok, I have reported it. Sent you an e-mail with the logs and left some screen shots in MBT. But every rule works fine but my logs ar flooded
You said that you left some "hooks" in the earlier problem with rules spanning over mid-night. Could it be related?@matohl No, I don't think it's related. There are some tricky side-effects with doing math with JavaScript dates, and I imagine something is running into a condition where it's hitting that. Everything the log says is correct, it's just not doing what it says it's going to do. It says it's going to sleep until a certain time, and then sleeps for no time at all, so I'm 99% its to do with the delay calculation in the timer object, which is as straight stupid simple as you can imagine it to be, and yet, not working, apparently, at least in some cases. And of course, I don't see it on mine.
-
Can you also look and see if there's a console.log file in your logs directory, and if it has any messages, and especially, rolling error messages at the same pace as the timer messages?
-
OK... in taking a second look at the logs, no two condition IDs are the same. You seem to use date/time conditions a lot?
So is this happening only when the Engine starts, or is it continuous in the logs?
Edit: FYI, these messages are at log level "always" from previous debugging, so I would expect a lot of them at engine startup, but once the engine starts, then really, it should quiet down to only when a timer expires and is rescheduled. And these may be the only messages you have. I guess I assumed they were rolling, but the log snippet you posted doesn't show that, so I need a better picture of when this is happening, and what's actually going on. I don't see email yet with the log file.
-
OK I need that log file, then.
-
OK... in taking a second look at the logs, no two condition IDs are the same. You seem to use date/time conditions a lot?
So is this happening only when the Engine starts, or is it continuous in the logs?
Edit: FYI, these messages are at log level "always" from previous debugging, so I would expect a lot of them at engine startup, but once the engine starts, then really, it should quiet down to only when a timer expires and is rescheduled. And these may be the only messages you have. I guess I assumed they were rolling, but the log snippet you posted doesn't show that, so I need a better picture of when this is happening, and what's actually going on. I don't see email yet with the log file.
@toggledbits said in Timers in my log:
... You seem to use date/time conditions a lot? ...
I change it every room individually. With lights sensors, time and sunrise/sunset conditions.... "or is it continuous in the logs?" ...
Yes, it is continuous... "it should quiet down to only when a timer expires and is rescheduled" ...
I don't see that in the logs -
"You seem to use date/time conditions a lot"
I live in Sweden were light changes dramatically over the year and we have sun from the east and darkness in the west in the morning and the opposite in the evening. After a few seasons I realize I had to change it individually for each room. Works perfectly in MSR, I use a SSD to my Pi so if the log is large it could probably handle it Due to this perhaps it is normal and I could move on but @kfxo signaled something similar. -
OK. Non-problem. Everything is fine. These are just debug messages from my previous investigation into scheduling of re-evaluations on time-based rules (PR #34 and 44 specifically). For that, I used the "always" log level (hence the "null" reported where the level goes in the logged messages). This is just normal start-up. When you start Reactor and it brings up the Engine, it reads all the rules, does an initial scan for dependencies, then evaluates all the conditions, which sets the timers for the next event based on current (post-startup) conditions. All is well.
The logs do not show they are rolling. If you had a continuous stream of timer messages, that would be noteworthy, but getting a timer messages for every time condition in any rule is expected at start-up. If there were further timer messages at unexpected time, the logs provided don't show that.
-
I'll put a proper level on that debug now that I'm not targeting that area as well. That will keep the log chatter down.
