Closed Bug 1018907 Opened 10 years ago Closed 10 years ago

timestamps for build directories are off by timezone offset (7 hours)

Categories

(Release Engineering :: General, defect)

x86_64
Windows 7
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: elbart, Assigned: ted)

References

Details

Attachments

(1 file)

Had a look at this, it's very confusing. It looks like the build times on inbound are *before* these patches were committed, so they're being missed. I.e. here's the json pushlog:

https://hg.mozilla.org/integration/mozilla-inbound/json-pushes?fromchange=41a54c8add09&tochange=2708630b4998

But if I actually scan the inbound archive using mozregression (http://inbound-archive.pub.build.mozilla.org/pub//mozilla.org/firefox/tinderbox-builds/mozilla-inbound-linux/) using a large range, here's when the corresponding builds inside that range are marked as being built:

--> Found 246aa86a5e0e 1400359532
   --> 246aa86a5e0e039f315c618021bfb603b12d6f33 Valid
--> Found 5bb98302ae5d 1400361992
   --> 5bb98302ae5d3ffa59382120539c93ca494e7e02 Valid
--> Found 2708630b4998 1400367691
   --> 2708630b4998462126ffa4e9a1befe4f46bdb02e Valid

For example, 246aa86a5e0e was supposed to have been pushed at 1400384702, almost 7 hours after the build. This doesn't make any sense to me: shouldn't builds come *after* pushes? Are we not adjusting for time zone differences or something? I asked RyanVM on irc, and he had no idea. Needinfo'ing :ted, who might?
Flags: needinfo?(ted)
The pushlog just inserts time.time() into the date field:
http://hg.mozilla.org/hgcustom/hghooks/file/0ee2f8335098/mozhghooks/pushlog.py#l65

I have no idea where the timestamp for the directory name comes from, it's way out of left field.

The pushlog shows:
"date": 1400384702, 

which is:
2014-05-17 20:45:02-07:00 (omg that's hard to calculate correctly in Python!)

the dated dir is:
1400359532

which comes out to:
2014-05-17 13:45:32-07:00

It looks like it's 7 hours off. The only thing that makes sense to me is if someone accidentally added the timezone offset into the timestamp here.

FWIW I surveyed some other dates and they all seem to match the pushlog's idea of date.

From firefox-32.0a1.en-US.linux-i686.txt:
20140517204532 (build ID)

From the Linux build log mozilla-inbound-linux-bm71-build1-build289.txt.gz:
starttime: 1400385287.41 (which is 2014-05-17 23:54:47.410000-07:00)
========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2014-05-17 20:54:47.407072) =========
Flags: needinfo?(ted) → needinfo?(catlee)
yeah, smells like a timezone issue. Pacific time is UTC-7 at the moment I believe?

If you ignore the hour offset, it looks like the dated dir is about 30s later than the push time, which makes sense. We generate the buildid when scheduling jobs, which happens after detecting a new hg change. This generated buildid is used to create the directory names.

What are the buildids for these builds? Do they match the directory names?
Flags: needinfo?(catlee)
The build ID is in comment 2, 20140517204532, compare vs. the pushlog date:

build id: 2014-05-17 20:45:32 
pushlog : 2014-05-17 20:45:02

But yeah, it's off by exactly 7 hours:
>>> pushdate = 1400384702
>>> dirdate = 1400359532
>>> dirdate - pushdate
-25170
>>> (dirdate + 7*60*60) - pushdate
30
>>>
Status: UNCONFIRMED → NEW
Component: mozregression → General Automation
Ever confirmed: true
Product: Testing → Release Engineering
QA Contact: catlee
Summary: Not picking up inbound-builds although they exist. → timestamps for build directories are off by timezone offset (7 hours)
I would say with 99% certainty that it's this function doing wrong datetime math:
http://hg.mozilla.org/build/tools/file/tip/stage/post_upload.py#l129
This should fix it, this code snippet works right locally:
>>> buildid = '20140517204532'
>>> calendar.timegm(pt.localize(datetime.strptime(buildid, "%Y%m%d%H%M%S")).utctimetuple())
1400384732
>>> 1400384732 - 1400384702
30

(that's the calculated timestamp from the build ID - the pushlog timestamp)

The only quirk is that we need pytz installed. I'll file a bug to make sure that's installed on the upload hosts.
Attachment #8439939 - Flags: review?(catlee)
Assignee: nobody → ted
Status: NEW → ASSIGNED
Depends on: 1025049
Attachment #8439939 - Flags: review?(catlee) → review+
For sanity I tested this locally (post_upload.py is kind of a pain to set up):
luser@eye7:/build/tools$ python stage/post_upload.py --product=firefox --version=32.0a1 --branch=branch --buildid=20140517204532 --no-shortdir --tinderbox-builds-dir=/tmp/tbox --release-to-tinderbox-dated-builds /tmp/temp /tmp/temp/firefox-32.0a1.en-US.win32.zip
sys.argv: ['stage/post_upload.py', '--product=firefox', '--version=32.0a1', '--branch=branch', '--buildid=20140517204532', '--no-shortdir', '--tinderbox-builds-dir=/tmp/tbox', '--release-to-tinderbox-dated-builds', '/tmp/temp', '/tmp/temp/firefox-32.0a1.en-US.win32.zip']
https://pvtbuilds2.dmz.scl3.mozilla.com/pub/mozilla.org/firefox/tinderbox-builds//tmp/tbox/1400384732/firefox-32.0a1.en-US.win32.zip
 
$ ls /tmp/builds/firefox/tinderbox-builds/tmp/tbox/1400384732/
firefox-32.0a1.en-US.win32.zip
https://hg.mozilla.org/build/tools/rev/1ddf84a3dc8c
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Blocks: 1025165
I pushed a workaround fix to mozregression, until the old builds expire: https://github.com/mozilla/mozregression/commit/5b0a02145b5f66adbfaa18e8d790457586a3e2f0
Component: General Automation → General
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: