I think I found a long-standing rounding error in this addon. I've been using it forever (and it's great btw) but for the longest time I've gotten the occasional duplicate library update that I couldn't explain. Tonight I finally decided to look into it and I think the problem comes in with this line (line 104 of service.py):
Code:
self.last_run = time.time() - (time.time() % 60)
That code is intended to capture the minute of the last run, but sometimes the float expression result will be just before the actual minute and thus croniter.get_next returns the next run as the one that just completed rather than the one that should next be scheduled. This then triggers the addon to update library again on the next minute click.
you can see some examples of what I'm talking about in this code snippet:
Code:
>>> print time.time();time.time() - (time.time() % 60);ceil(time.time() - (time.time() % 60));(time.time()+1) - (time.time() %60)
1394598973.24
1394598959.999999
1394598960.0
1394598960.9999962
This also shows the potential fixes. You can either add 1 to time.time() (if you don't want to import math) or you can take the ceiling of the existing result to force it to round up
Also, here's a log snippet that shows the problem occurring (in my case my cron expression is */15 * * * *). Note, I added some logging to see when last_run was read and written.
Code:
00:15:00 T:139895397181184 NOTICE: service.libraryautoupdate: Starting network check
00:15:00 T:139895397181184 NOTICE: service.libraryautoupdate: Update Video Library
00:15:00 T:139895397181184 NOTICE: Next Run: 1394598600.0
00:15:00 T:139895380395776 NOTICE: Thread CVideoInfoScanner start, auto delete: false
00:15:00 T:139895380395776 NOTICE: VideoInfoScanner: Starting scan ..
00:15:01 T:139895380395776 NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
00:15:01 T:139895397181184 NOTICE: Writing Last Run: 1394597699.999999
00:15:02 T:139895397181184 NOTICE: service.libraryautoupdate: update timers
00:15:02 T:139895397181184 NOTICE: Next Run: 1394597700.0
00:15:09 T:139894118627072 NOTICE: AddOnLog: MythTV cmyth PVR Client: Process - Event unknown, databuf:
00:16:00 T:139895397181184 NOTICE: Previous line repeats 5 times.
00:16:00 T:139895397181184 NOTICE: service.libraryautoupdate: Starting network check
00:16:00 T:139895397181184 NOTICE: service.libraryautoupdate: Update Video Library
00:16:00 T:139895397181184 NOTICE: Next Run: 1394598600.0
00:16:00 T:139895388788480 NOTICE: Thread CVideoInfoScanner start, auto delete: false
00:16:00 T:139895388788480 NOTICE: VideoInfoScanner: Starting scan ..
00:16:00 T:139895388788480 NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
00:16:00 T:139895388788480 NOTICE: Thread Jobworker start, auto delete: true
00:16:01 T:139895397181184 NOTICE: Previous line repeats 1 times.
00:16:01 T:139895397181184 NOTICE: Writing Last Run: 1394597760.000000
00:16:02 T:139895397181184 NOTICE: service.libraryautoupdate: update timers
00:16:02 T:139895397181184 NOTICE: Next Run: 1394598600.0
Hope this helps fix this issue. I'm just glad at this point I finally understand why it happens as it's driven me crazy for the longest time.