whisper.InvalidTimeInterval from carbon-sync

[garrettux]

Hi, we're trying to use carbon-sync, and are running into whisper.InvalidTimeInterval every time. It doesn't seem to be an issue with specific whisper files, because it happens at a different point in the sync every time, and seems to happen regardless of batch size. Here's the traceback:

Traceback (most recent call last):
  File "/opt/graphite/bin/carbon-sync", line 9, in <module>
    load_entry_point('carbonate==0.2.2', 'console_scripts', 'carbon-sync')()
  File "/opt/graphite/lib/carbonate-0.2.2-py2.6.egg/carbonate/cli.py", line 197, in carbon_sync
    args.storage_dir, args.rsync_options)
  File "/opt/graphite/lib/carbonate-0.2.2-py2.6.egg/carbonate/sync.py", line 116, in run_batch
    merge_elapsed = sync_batch(metrics_to_heal)
  File "/opt/graphite/lib/carbonate-0.2.2-py2.6.egg/carbonate/sync.py", line 57, in sync_batch
    heal_metric(staging, local)
  File "/opt/graphite/lib/carbonate-0.2.2-py2.6.egg/carbonate/sync.py", line 72, in heal_metric
    fill_archives(source, dest, time())
  File "/opt/graphite/lib/carbonate-0.2.2-py2.6.egg/carbonate/fill.py", line 110, in fill_archives
    fill(src, dst, gapstart - step, start)
  File "/opt/graphite/lib/carbonate-0.2.2-py2.6.egg/carbonate/fill.py", line 72, in fill
    (timeInfo, values) = fetch(src, fromTime, untilTime)
  File "/opt/graphite/lib/whisper.py", line 667, in fetch
    return file_fetch(fh, fromTime, untilTime)
  File "/opt/graphite/lib/whisper.py", line 683, in file_fetch
    raise InvalidTimeInterval("Invalid time interval")
whisper.InvalidTimeInterval: Invalid time interval

[jssjr]

Hi @garrettux! I feel like a 💩 for not getting back to you quickly. Did you ever figure this out?

Out of curiosity, are the clocks on both machines in sync? whisper-fill (and by extension, carbon-sync) relies on python calling time.time() to determine the upper bound for datapoints to sync.

[mrmanc]

Hi, I’m currently experiencing this problem on two CentOS 6.4 servers where the time appears to be in sync. I checked /var/log/ntpd and can see adjustments being made once an hour but there was nothing for five minutes before the last failure. Is there any more information which might help with diagnosis?

  - Syncing 450 of 1000 metrics. Avg: 0.000338s  Time Left: 0:00:00.186037s (45%)
Traceback (most recent call last):
  File "/usr/bin/carbon-sync", line 10, in <module>
    load_entry_point('carbonate==0.2.2', 'console_scripts', 'carbon-sync')()
  File "/usr/lib/python2.6/site-packages/carbonate/cli.py", line 197, in carbon_sync
    args.storage_dir, args.rsync_options)
  File "/usr/lib/python2.6/site-packages/carbonate/sync.py", line 116, in run_batch
    merge_elapsed = sync_batch(metrics_to_heal)
  File "/usr/lib/python2.6/site-packages/carbonate/sync.py", line 57, in sync_batch
    heal_metric(staging, local)
  File "/usr/lib/python2.6/site-packages/carbonate/sync.py", line 72, in heal_metric
    fill_archives(source, dest, time())
  File "/usr/lib/python2.6/site-packages/carbonate/fill.py", line 110, in fill_archives
    fill(src, dst, gapstart - step, start)
  File "/usr/lib/python2.6/site-packages/carbonate/fill.py", line 72, in fill
    (timeInfo, values) = fetch(src, fromTime, untilTime)
  File "/usr/local/graphite/lib/python2.6/site-packages/whisper.py", line 668, in fetch
    return file_fetch(fh, fromTime, untilTime)
  File "/usr/local/graphite/lib/python2.6/site-packages/whisper.py", line 684, in file_fetch
    raise InvalidTimeInterval("Invalid time interval")
whisper.InvalidTimeInterval: Invalid time interval

$ uname -a
Linux [redacted] 2.6.32-358.el6.x86_64 #1 SMP Fri Feb 22 00:31:26 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux
$ rpm -qa | grep carbon
carbon-0.9.10-1.noarch
$ rpm -qa | grep whisper
whisper-0.9.10-1.noarch
$ pip show carbonate
---
Name: carbonate
Version: 0.2.2
Location: /usr/lib/python2.6/site-packages
Requires: carbon, whisper

$ python
Python 2.6.6 (r266:84292, Feb 22 2013, 00:00:18) 
[GCC 4.4.7 20120313 (Red Hat 4.4.7-3)] on linux2
Type "help", "copyright", "credits" or "license" for more information.

[mrmanc]

I added some debug to the local whisper.py file from the latest version and can see that there is a comparison between two equal timestamps which is causing the exception. Looking at the logic it looks like there was a flaw in the logic that was fixed in graphite-project/whisper@cd389a5 where it threw an exception for equal timestamps when it looks like what was intended was an error when the fromTime is after untilTime.

I’ve patched the local version and run again and I have a different error. Progress!

[deniszh]

So, it was bug in whisper. Closing then.