skoczen / will

Will is a simple, beautiful-to-code bot for slack, hipchat, and a whole lot more.
https://heywill.io
MIT License
406 stars 171 forks source link

@periodic task seems to be changing every day despite fixed hour and minutes #295

Closed wontonst closed 6 years ago

wontonst commented 7 years ago

Here is my code

@periodic(hour='10', minute='30', day_of_week='mon,wed,thu,fri')
    def standup(self):
        self.say(self.chefs_message, room=self.available_rooms['CHEF'], notify=True)

image

The times seems to be migrating earlier and earlier. Today it was set for 11:30AM but will sent the message out at 11:19AM.

skoczen commented 7 years ago

That's certainly odd - thanks for the report! Will set up some test cases here to try and reproduce and isolate what's happening!

For clarity - is this on 1.0.x or 2.x?

wontonst commented 7 years ago

will==1.0.0

On Tue, Oct 24, 2017 at 1:48 PM, Steven Skoczen notifications@github.com wrote:

That's certainly odd - thanks for the report! Will set up some test cases here to try and reproduce and isolate what's happening!

For clarity - is this on 1.0.x or 2.x?

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/skoczen/will/issues/295#issuecomment-339126235, or mute the thread https://github.com/notifications/unsubscribe-auth/AB773I_seUOZ7r2lDN3jRiNYCRgarFOIks5svk0agaJpZM4QE4Mh .

skoczen commented 7 years ago

Great, thanks - and to double-check, the server time has been consistent?

For reference - I've had will running on a 10AM standup meeting for the length of years, and haven't seen the behavior you're seeing (it was at 10 sharp, every day.) So trying to figure out what's different!

wontonst commented 7 years ago

When I first saw the discrepancy, I went to the box and ran the date cmd. The date was correct so will was off, unless will is polling a different system time?

On Tue, Oct 24, 2017 at 4:14 PM, Steven Skoczen notifications@github.com wrote:

Great, thanks - and to double-check, the server time has been consistent?

For reference - I've had will running on a 10AM standup meeting for the length of years, and haven't seen the behavior you're seeing (it was at 10 sharp, every day.) So trying to figure out what's different!

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/skoczen/will/issues/295#issuecomment-339164404, or mute the thread https://github.com/notifications/unsubscribe-auth/AB773OIj-tMRIG6XIoZg5YjJIlhrtFl3ks5svm9NgaJpZM4QE4Mh .

skoczen commented 7 years ago

Nope, it's just datetime.datetime.now(). Adding some logging to see if something odd was added to ChronTrigger's get_next_fire_time.

skoczen commented 7 years ago

@wontonst this is what I'm seeing thus far:

screen shot 2017-10-26 at 11 49 40 am

I have daily and hourly tests running, and all seems sane. Any more updates on your side?

wontonst commented 6 years ago

Didn't get a chance to dig deeper. I restarted the box that runs will and as I suspected, it reset and is now off by 1 minute. Tomorrow it will be off by 2. Strange.

skoczen commented 6 years ago

So bizarre. Is the redis (or whatever storage you're using) backend on the same machine, or a different one?

wontonst commented 6 years ago

Great suggestion. I'm running redis in a docker container on the same machine as will. Looking at the date, somehow they're off by 11 seconds. I bet by tomorrow standup time it'll be off by 60+ seconds which would be why I'm seeing the strange behavior.

On Thu, Oct 26, 2017 at 1:55 PM, Steven Skoczen notifications@github.com wrote:

So bizarre. Is the redis (or whatever storage you're using) backend on the same machine, or a different one?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/skoczen/will/issues/295#issuecomment-339798177, or mute the thread https://github.com/notifications/unsubscribe-auth/AB773Jl1sqKf_dfpOfsjkq3d5mZLoJ_Hks5swPHOgaJpZM4QE4Mh .

skoczen commented 6 years ago

Super interesting. I'd hope that will should be immune to that kind of problem, as it's weird that the time on a storage backend would make it into will.

Out of curiosity, if you can and have a chance, please try the 2.0 branch and see if it still happens. Storage is now encrypted, so the time on the storage machine shouldn't make any difference (as it's now zero-knowledge WRT its contents). Wonder if redis is doing some magical conversion if it can read the data?

wontonst commented 6 years ago

Hitting

Traceback (most recent call last):
  File "/run_will.py", line 2, in <module>
    from will.main import WillBot
  File "/usr/local/lib/python3.4/site-packages/will/main.py", line 29, in <module>
    from will.backends import analysis, execution, generation, io_adapters
  File "/usr/local/lib/python3.4/site-packages/will/backends/__init__.py", line 1, in <module>
    from will.backends import analysis
  File "/usr/local/lib/python3.4/site-packages/will/backends/analysis/__init__.py", line 1, in <module>
    from .nothing import NoAnalysis
  File "/usr/local/lib/python3.4/site-packages/will/backends/analysis/nothing.py", line 5, in <module>
    from .base import AnalysisBackend
  File "/usr/local/lib/python3.4/site-packages/will/backends/analysis/base.py", line 9, in <module>
    from will.mixins import PubSubMixin, SleepMixin
  File "/usr/local/lib/python3.4/site-packages/will/mixins/__init__.py", line 4, in <module>
    from will.mixins.naturaltime import NaturalTimeMixin
  File "/usr/local/lib/python3.4/site-packages/will/mixins/naturaltime.py", line 5, in <module>
    from natural.date import day
ImportError: No module named 'natural'

Looks like some weirdness in https://github.com/skoczen/will/pull/258/files#diff-7fe11226cff646f5d9f35faa76217059R13

I think I'll hold off on testing 2.0 until you get the docs up, it looks like the changes are quite extensive and I don't have the bandwidth to migrate at the moment.

It would be nice for will to be robust enough to handle this case but in my opinion it's really on Docker to get their act together in https://forums.docker.com/t/time-in-container-is-out-of-sync/16566

skoczen commented 6 years ago

@wontonst that should be just a pip install fix. Will see why it's not being pull into the setup.py install script!

Either way, pip install -e git+https://github.com/heywill/natural#egg=natural should get you sorted.

Migration to 2.x should be pretty straightforward (and Will walks you through them on start), but hear you on docs - aiming to get them up and out this week.

skoczen commented 6 years ago

@wontonst just a quick update - I've pushed a fix that will auto-install the dependencies, and tested E2E here with a fresh install using my old, will 1.0 codebase. Things Just Worked here.

Totally get the bandwidth limits, all good. If you do have a few moments, would love to hear how the latest works for you, and if it solves your issue.

(Also, clearly we can't do much about the clock being off in the docker container Will's running in (nor do I think we should, even if we could.))

skoczen commented 6 years ago

This looks to be working for multiple people on 2.0.1beta > 2, so closing this up - please reopen if you're still seeing it!