X-Axis Incorrect on some graphs

[Nicholas Leskiw]

It appears that my time is shifted...I'm not sure if this is a timezone issue or what, but it doesn't always affect the labels. See screenshot. I selected June 7 12:00 AM - 11:59PM for today for the top graph, (1 day) and May 31 12:00 AM - June 7 11:59 pm for the bottom graph (7 day). I'm not sure how it could be a timezone issue if one graph is unaffected and the other is, just by changing the date range. Can someone else test 0.9.6 and see if this happens to them? Just maybe it looks like the text is ending at the correct time but the major gridline is off as well so that might just be coincidence.

[Nicholas Leskiw (nleskiw)]

Can anyone confirm this bug is real (and not PEBKAC?)

[chrismd (chrismd)]

I'm not sure I can confirm or deny this bug. I just tried looking at a traffic graph in my own graphite system at the past 1 day, 2 days, etc... back to 14 days. Each time the labels/times look correct. Then again it's not a perfectly valid test because I'm running off trunk, not 0.9.6. Could you try using trunk (just run "python setup.py sdist" to create your own release tarball from a trunk checkout). Nothing major has changed since 0.9.6 but lots of random bugs have been fixed.

[chrismd (chrismd)]

I take it back, I can confirm the bug in trunk. The x-axis configuration is determined by the ratio of number of pixels to number of datapoints. My graphs were too wide originally and didn't force enough aggregation to hit the bug, the problem is this block of code in glyph.py, setupXAxis, around line 677.

    if self.xConf['labelUnit'] >= DAY: #JIRA SOS-80
      if daylight:
        self.utcAdjustment = altzone
      else:
        self.utcAdjustment = timezone
    else:
      self.utcAdjustment = 0

If you comment out this entire block and replace it with "self.utcAdjustment = 0" then the problem appears to go away. The thing is, I remember adding this code many years ago for a reason... it was before Graphite was open sourced so it is not on the launchpad bug tracker and I no longer have access to the bug tracker where the history resides. From what I remember the problem was essentially what you have described, except that it only occurred when this code was *not* present, and now we seem to have the opposite situation.

So, work around for now is to comment this out, but I'd like to get a better understanding of what the correct approach is and why before closing out this bug. Good catch.

[Nicholas Leskiw (nleskiw)]

I bet the problem was that X labels got aligned with even multiples of the xLabelUnit. When that was anything but DAY everything worked fine. But when it was DAY, the local timezone's offset from UTC caused the beginning of the day to get misaligned by the amount of the offset.

For example:
DAY = 60 * 60 * 24
now = time.time()
midnight = now - (now % DAY) #this is midnight UTC, not local time!
print time.ctime(midnight) #prints 5 hours prior to midnight (or whatever the offset is)

[Nicholas Leskiw (nleskiw)]

Well, I bet that's what the JIRA ticket would say if you could still look at it, anyway.

[chrismd (chrismd)]

You're right nick, that is exactly what the problem was.

On Jun 15, 2010 2:25 PM, "Nicholas Leskiw" <email address hidden> wrote:

Well, I bet that's what the JIRA ticket would say if you could still
look at it, anyway.

--
X-Axis Incorrect on some graphs
https://bugs.launchpad.net/bugs/591948
You received this bug no...
Status in Graphite - Enterprise scalable realtime graphing: Confirmed

Bug description:
It appears that my time is shifted...I'm not sure if this is a timezone
issue or w...

[Christian (cboitel)]

I have similar problems that also manifest when building graphs covering multple months:
=> the labels displayed are incorrects: i can get twice the same month and after every is shifted

I looked at the code in render/glyph.py and compared it to rrd_graph.c. I found rrd is now using find_first_time and find_next_time internal functions to define where grids and labels are to be drawn. Maybe we could adapt glyph.py to work accordingly.

[Christian (cboitel)]

The attached patch applies to lib/graphite/render/glyph.py
=> it is written based on 0.96 version

It fixes:
1/ labels being displayed
2/ x minor and major grid line generation:
     * time grid lines no longer appear shifted in graphs
     * pbs occurring when minor/major grid lines should align and do not due to python float precision issues

As mentioned in an earlier comment, i ported the find_first_time/find_next_time functions available in rrdtool graph source code and adapt it.

[Christian (cboitel)]

I thought i could also fix horizontal grid lines alike the horizontal ones (due to float precision issues)

[chrismd (chrismd)]

Christian, I reviewed your patches and it is a good approach. I actually just changed from using raw epoch times to datetime objects in order to better support user-specified timezones, so I had to reimplement your approach that way but all in all it appears to work quite well. This is now in trunk.

Thanks

[Martel (martel)]

I thing this bug may be still around.

Last two hours shows actual time as 3:42 instead of 10:42.

See attached screenshot.

[Martel (martel)]

What's more, graphite error log contains correct system time:

{{{
[Wed Dec 28 10:43:28 2011] [error] Could not import graphite.local_settings, using defaults!
[Wed Dec 28 10:43:35 2011] [error] Could not import graphite.local_settings, using defaults!
[Wed Dec 28 10:43:56 2011] [error] Could not import graphite.local_settings, using defaults!
[Wed Dec 28 10:44:05 2011] [error] Could not import graphite.local_settings, using defaults!
[Wed Dec 28 10:44:15 2011] [error] Could not import graphite.local_settings, using defaults!
}}}

And graphite info.log contains INCORRECT dates:

{{{
Wed Dec 28 03:41:03 2011 :: find_view query=* local_only=0 matches=3
Wed Dec 28 03:41:04 2011 :: find_view query=crm-test.* local_only=0 matches=2
Wed Dec 28 03:41:06 2011 :: find_view query=crm-dev.* local_only=0 matches=3
Wed Dec 28 03:41:08 2011 :: find_view query=crm-dev.jvm.* local_only=0 matches=6
Wed Dec 28 03:41:25 2011 :: find_view query=crm-test.jvm.* local_only=0 matches=5
Wed Dec 28 03:43:28 2011 :: graphite.wsgi - pid 57885 - reloading search index
Wed Dec 28 03:43:28 2011 :: [IndexSearcher] performing initial index load
Wed Dec 28 03:43:28 2011 :: [IndexSearcher] reading index data from /opt/graphite/storage/index
Wed Dec 28 03:43:28 2011 :: [IndexSearcher] index reload took 0.000475 seconds (0 entries)
Wed Dec 28 03:43:35 2011 :: graphite.wsgi - pid 57893 - reloading search index
Wed Dec 28 03:43:35 2011 :: [IndexSearcher] performing initial index load
Wed Dec 28 03:43:35 2011 :: [IndexSearcher] reading index data from /opt/graphite/storage/index
Wed Dec 28 03:43:35 2011 :: [IndexSearcher] index reload took 0.000006 seconds (0 entries)
}}}