freakent / node-red-contrib-sunevents

A node for node-red that generates events based on the position of the Sun at the appropriate time of day.
Apache License 2.0
15 stars 14 forks source link

Node doesn't output anything anymore. It's getting the wrong timezone? #6

Closed recklessnl closed 4 years ago

recklessnl commented 4 years ago

I love using this node for home automation purposes but lately I've noticed that it does not output anything anymore after updating my Node-RED instance to 1.0.3.

I've let it run overnight, I've rebooted the Node-RED container, reinstalled, nothing makes it work anymore. Checking the logs, it seems that it's mistaken my timezone for some reason, with values being wayyy off:

15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] Calculating sun event times for some_latitude, some_longitude.
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Initialising job to calculate sunevents
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Calculating times for Sat Feb 15 2020 23:59:59 GMT-0600
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting solarNoon Tomorrow at 12:02 PM in 34 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting nadir Tomorrow at 12:02 AM in 22 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting sunrise Tomorrow at 6:35 AM in 29 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting sunset Tomorrow at 5:29 PM in 40 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting sunriseEnd Tomorrow at 6:38 AM in 29 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting sunsetStart Tomorrow at 5:27 PM in 40 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting dawn Tomorrow at 6:09 AM in 28 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting dusk Tomorrow at 5:56 PM in 40 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting nauticalDawn Tomorrow at 5:39 AM in 28 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting nauticalDusk Tomorrow at 6:26 PM in 41 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting nightEnd Tomorrow at 5:09 AM in 27 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting night Tomorrow at 6:55 PM in 41 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting goldenHourEnd Tomorrow at 7:11 AM in 29 hours
15 Feb 01:24:42 - [info] [sun events:f8fcd0e.096f9b] [sunevents] Emitting goldenHour Tomorrow at 4:54 PM in 39 hours

I'm not in a GMT timezone - but I checked the containers, and all dates and times are current and correct. What gives?

freakent commented 4 years ago

I haven't touched this code for years! But I think it is time I updated it for the latest node-red. I will start testing a V2 this week. No commitments though.

recklessnl commented 4 years ago

Thank you for looking into it!

freakent commented 4 years ago

Try install my beta V2 version into your node-red user directory. npm install https://github.com/freakent/node-red-contrib-sunevents#v2

recklessnl commented 4 years ago

Thanks, I will try this shortly. I noticed you didn't update the suncalc version up to v1.8.0 in the commit, is that something that you're going to implement as well?

I also think issue #4 offered some nice-to-have features as well, which I think would be great for v2 of your node.

freakent commented 4 years ago

@recklessnl Thanks for spotting that the module dependencies did not update. For some reason it was not show that to me. I forced an update of the module dependencies. If you do an npm update you should get my updated version.

freakent commented 4 years ago

I also looked close at #4, I need more info on each use case to figure out how to include those features.

recklessnl commented 4 years ago

@freakent I am running Node-RED in a docker container, so I usually install everything via the palette manager.

Do you think you'll be able to release the first 2.0 candidate officially soon once no bugs have been discovered? I'll be able to test on my end for sure.

freakent commented 4 years ago

Sure, the way nodes are install have changed since I originally wrote this. How do you install nodes in your Docker container? Are you pulling them from npm? I can’t even remember whether I pushed v1 to npm or not. Also what platform are you using Docker on? I run my node red on an older Raspberry Pi. I would like to see your Docker file.

recklessnl commented 4 years ago

It's very simple actually! No commands necessary - I go to the menu in the top right, go to Palette, search for the node I want and press install. Then I simply restart the node-red docker container and I can use the node! I believe this way of installation is the recommended way to install now, and it's easier for newbies too since it's all done in the GUI.

I can share my dockerfile later, but I do recommend you read up on the small changes that node red version 1.0 made, there might be some things that are different compared to 5 years ago for node authors like yourself.

freakent commented 4 years ago

I hadn't realised I had posted my original node to npm and I am amazed that weekly downloads are 128! I have pushed the latest 2.0.0 version up to npm. According to node-red site it can take a couple of hours for their index to pick it up, but try to update your pallete when you can.

recklessnl commented 4 years ago

@freakent I'm telling you, it's more popular than you think and it will only grow from here!

I just installed it tonight, I should be able to tell by tomorrow if everything works correctly.

romefig commented 4 years ago

Hi, @freakent! First of all thanks for a cool program! It's just what I'm looking for! I'm using it (v2.0.0) within Node-RED. I would like to report couple of bugs:

  1. Latitude/Longitude values are not saving. After double-click empty field is displayed.
  2. After deploy I see many events (generated messages) at once. https://img.vim-cn.com/8a/a2b215bbb6205ef17564f660afd3c501de9705.png
recklessnl commented 4 years ago

I can unfortunately confirm that this didn't work for me overnight. It was supposed to trigger events and I was monitoring the output with a debug node, but nothing got triggered: there was no output from the sunevents node whatsoever.

@freakent Can you check on your end if it works? I have the latest version of Node-RED docker container.

recklessnl commented 4 years ago

Here's something I noticed @freakent: every time I reboot the node-red container, I can see that the sunevents node always start calculating the next sunevents at precisely at 23:59:59. It doesn't matter what time it is when I restart it, whether it's 7am or 12 noon, it will always start calculating at 23:59:59.

It got my latitude and longitude right, it also got my timezone right, but it's not close to that time now. So there's bug somewhere in getting the correct local time of the system it's running on (which in my case is the official node-red docker container).

freakent commented 4 years ago

Hi @recklessnl, I did find and fix a bug affecting the scheduling. I have pushed a new 2.0.1 version up to npm so you should be able to pull that into your node-red pallet. If you have further problems, please enable "Log event calculations?" and send me your node-red log file.

What you are seeing is exactly how it should work. When you first deploy the node (or start your node-red), this node calculates when each sun event will happen that day and schedules timer events for each sun event that has not already passed. It then schedules a job to repeat the same calculations for the next day at midnight and so on. The suncalc library this node depends on calculates all the sun events for the current day, so this node has to be triggered every day at midnight to set up the timers for the following day. If you enable the "Log event calculations?", you will be able to see all these calculations taking place each day.

recklessnl commented 4 years ago

@freakent it's not showing an update for the sunevents node yet, so I can't test it right now, but let me show you what I mean with the bug. Notice the time when it restarted (close to 1am) and the resulting calculations for that day.

28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Calculate today's remaining sunevents
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Calculating times for Fri Feb 28 2020 23:59:59 GMT-0700
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting nadir Tomorrow at 12:01 AM in 22 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting nightEnd Tomorrow at 4:54 AM in 26 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting nauticalDawn Tomorrow at 5:24 AM in 27 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting dawn Tomorrow at 5:53 AM in 27 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting sunrise Tomorrow at 6:19 AM in 28 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting sunriseEnd Tomorrow at 6:22 AM in 28 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting goldenHourEnd Tomorrow at 6:54 AM in 28 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting solarNoon Tomorrow at 12:01 PM in 34 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting goldenHour Tomorrow at 5:07 PM in 39 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting sunsetStart Tomorrow at 5:39 PM in 39 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting sunset Tomorrow at 5:42 PM in 39 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting dusk Tomorrow at 6:08 PM in 40 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting nauticalDusk Tomorrow at 6:38 PM in 40 hours
28 Feb 00:58:16 - [info] [sun events:9397ac6f.7d4db8] [sunevents] Emitting night Tomorrow at 7:07 PM in 41 hours

When this command was run, the next nightEnd event should be hours away, not 26 hours away. Every time the node-red container restarts (and in Docker, you have to restart the container almost every time a node has been updated) it might output the wrong timings like above. Not sure if the new version fixes that (don't see the update yet), but surely this isn't expected behavior?

freakent commented 4 years ago

It almost certainly looks like a timezone issue. I have tested with various time zone settings but I am not getting the behaviour you are seeing. I have pushed out another new version (v2.0.2) with more debugging and a few more checks where ever timezones might be an issue. Please keep sending me output of you logs as they really help. Also, it might simply be a matter of telling node exactly wihich timezone you are in by launching node-red like this: % TZ="America/Phoenix" node-red

freakent commented 4 years ago

One more question, why is the node-red flow restarting at 00:58? Are you awake and manually restarting it or is that the time it is automatically running?

freakent commented 4 years ago

As you are running in docker, did you try this? docker run -it -p 1880:1880 --name mynodered -e TZ=America/Phoenix nodered/node-red

See https://nodered.org/docs/getting-started/docker#setting-timezone

recklessnl commented 4 years ago

The new update works now! I also like the extra debugging. On my end, I did already have the TZ env in the docker command, but there was also something in the settings.js file in the node-red data folder that might have been causing this issue (process.env.TZ was set, I just commented it out). Removing that and just having the TZ env in the docker command fixed it for me.

Thank you @freakent for fixing this bug and updating the node! My only last request would be to have the node save the latitude and longitude values, so that you can copy the node already filled in. Currently, when you have filled those values in and copy the node, it loses those values. It would be easier to have the node remember those values when the node is being copied.

But since my timezone issue is fixed, I will close this. Thanks again!

freakent commented 4 years ago

🕺🕺🕺

freakent commented 3 years ago

Hi, I have a new Beta version of this SunEvents node that I think addresses this issue. Want to test it?

freakent commented 3 years ago

To try the V3 Beta follow the link to this issue:

21 V3 Beta Testers

Thanks!