Bug in has_been?

[sspencer-hubble]

Please observe the following code:

import pycron
from datetime import datetime

last_run = datetime.strptime("11/12/2021 15:29:55", "%m/%d/%Y %H:%M:%S")
current_time = datetime.strptime("11/12/2021 15:30:56", "%m/%d/%Y %H:%M:%S")

print(last_run)
print(current_time)

print(pycron.has_been("*/10 * * * *", last_run, current_time))

Output:

2021-11-12 15:29:55
2021-11-12 15:30:56
True

It is my understanding that pycron should read that cron timing as "Run every 10 minutes". has_been should return False, in the above example because the last_run date/time and the current_time are about a minute apart. So given that, it should return False as at least 10 minutes has not elapsed. However, if you run the above code, pycron.has_been is returning True. So either, there is a pretty serious bug, or I don't understand what I'm doing. Any help resolving this would be much appreciated.

[kipe]

IMO the current behavior is correct. The last run as been before the code should have been last triggered.

Everything the */10 does is tell that the run should occur at minutes 0, 10, 20, 30, 40, and 50. As the last_run is before the minute 30, but current_time is after 30, the behavior is correct. There isn't such a concept as "Run every 10 minutes" in cron, as it's based on absolute times instead of relative.

//E: https://crontab.guru/#/10_*_

[sspencer-hubble]

Alright. Thank you for clearing up my misconception.

[sspencer-hubble]

Follow-up question then. Should this also be returning true? Because it is:

import pycron
from datetime import datetime

last_run = datetime.strptime("11/12/2021 15:30:55", "%m/%d/%Y %H:%M:%S")
current_time = datetime.strptime("11/12/2021 15:31:56", "%m/%d/%Y %H:%M:%S")

print(last_run)
print(current_time)

print(pycron.has_been("*/10 * * * *", last_run, current_time))

If the code is functioning as intended, and this has_been method was run once every minute, it would fire twice in a row: once when the current_time and the last_run are on either side of a barrier and once, when the last_run clears that barrier. That seems not correct to me?

[kipe]

hmm, that indeed does seem like a bug, let me double check

[kipe]

Hmm, this is actually bit of a tricky one. As cron doesn't handle seconds, the last_run at 15:30 is the cause for trigger. As the last_run matches, it's reported as True even though there isn't a trigger between the times.

Not sure what to do about this, to be honest the only solution would be to round-up the last_run to next minute, but that doesn't feel correct from the library standpoint.

[sspencer-hubble]

I still think there is a problem, if we remove seconds from the equation:

import pycron
from datetime import datetime

for i in range(29,31):
    last_run = datetime.strptime(f"11/12/2021 15:{i}", "%m/%d/%Y %H:%M")
    current_time = datetime.strptime(f"11/12/2021 15:{i+1}", "%m/%d/%Y %H:%M")

    print(last_run)
    print(current_time)

    print(pycron.has_been("*/10 * * * *", last_run, current_time))

OUTPUT

2021-11-12 15:29:00
2021-11-12 15:30:00
True
2021-11-12 15:30:00
2021-11-12 15:31:00
True

Rounding doesn't really save me, it just moves the problem back a minute.

[sspencer-hubble]

BTW, appreciate the quick responses.

[kipe]

As you can see, both tests include the 15:30:00 -> both should return True, as 30 is a minute when the cron matches. If you try with minutes 31 and 39, it works correctly.

The way I meant rounding up in the previous was that the 15:30:55 would be rounded up to 15:31:00 and then you're comparing between 15:31:00 and 15:31:56 -> no match, False as it should be.

I'm normally very slow to respond, but a bit drunk now and this is interesting issue :D

[kipe]

In essence, this could be solved if before https://github.com/kipe/pycron/blob/master/pycron/init.py#L132 since would be increased by 1 minute, as it's done in the loop. And then behavior in this case would be correct, still need to figure out if it would break something else.

[kipe]

Yeah, the behavior seems correct. But as cron doesn't care about seconds, this can be fixed just by adding 1 minute before the loop to since.

Would be a fine first pull request ;)

[sspencer-hubble]

Update from my now deleted status. Rounding doesn't appear to fix anything, just moves the problem around:

import pycron
import datetime

def roundTime(dt=None, roundTo=60):
   """Round a datetime object to any time lapse in seconds
   dt : datetime.datetime object, default now.
   roundTo : Closest number of seconds to round to, default 1 minute.
   Author: Thierry Husson 2012 - Use it as you want but don't blame me.
   """
   if dt == None : dt = datetime.datetime.now()
   seconds = (dt.replace(tzinfo=None) - dt.min).seconds
   rounding = (seconds+roundTo/2) // roundTo * roundTo
   return dt + datetime.timedelta(0,rounding-seconds,-dt.microsecond)

print("Round from 50 seconds:\n")

for i in range(28,33):
    last_run = datetime.datetime.strptime(f"11/12/2021 15:{i}:50", "%m/%d/%Y %H:%M:%S")
    current_time = datetime.datetime.strptime(f"11/12/2021 15:{i+1}:51", "%m/%d/%Y %H:%M:%S")

    last_run = roundTime(last_run)

    print(last_run)
    print(current_time)
    
    cron = "*/10 * * * *"

    status = pycron.has_been(cron, last_run, current_time)

    print(f"{status}\n")


print("=========================================\n\nRound from 01 Seconds:\n")


for i in range(28,33):
    last_run = datetime.datetime.strptime(f"11/12/2021 15:{i}:01", "%m/%d/%Y %H:%M:%S")
    current_time = datetime.datetime.strptime(f"11/12/2021 15:{i+1}:51", "%m/%d/%Y %H:%M:%S")

    last_run = roundTime(last_run)

    print(last_run)
    print(current_time)

    cron = "*/10 * * * *"

    status = pycron.has_been(cron, last_run, current_time)

    print(f"{status}\n")

OUTPUT

Round from 50 seconds:

2021-11-12 15:29:00
2021-11-12 15:29:51
False

2021-11-12 15:30:00
2021-11-12 15:30:51
True

2021-11-12 15:31:00
2021-11-12 15:31:51
False

2021-11-12 15:32:00
2021-11-12 15:32:51
False

2021-11-12 15:33:00
2021-11-12 15:33:51
False

=========================================

Round from 01 Seconds:

2021-11-12 15:28:00
2021-11-12 15:29:51
False

2021-11-12 15:29:00
2021-11-12 15:30:51
True

2021-11-12 15:30:00
2021-11-12 15:31:51
True

2021-11-12 15:31:00
2021-11-12 15:32:51
False

2021-11-12 15:32:00
2021-11-12 15:33:51
False

IDK what the solution is, but what I know is that has_been is not a workable method for me as I cannot have code firing twice back-to-back at each cron barrier. Since I don't know anything about the cron dates that are handed to me, I think I'll just have to use is_now, and hope that my schedule fires at least once a minute (and not run again if my last_run was within the same minute)

[kipe]

Here, the issue is that

2021-11-12 15:29:00
2021-11-12 15:30:51
True

2021-11-12 15:30:00
2021-11-12 15:31:51
True

both include the trigger time in either start or end times -> True. If you just try adding 1 minute to the start time instead of rounding up, the issue should be fixed.

Still not sure how to handle this correctly, as IMO the correct behaviour is to ignore seconds and tell if the cron match between (including) those timestamps. To be honest, as long as you make sure your code isn't run more than once per minute, you should be fine.

[Wissperwind]

I think this behaviour is good. Both include the trigger time, both trigger.