1089926 - Two win32 partner repack jobs for 33.0.2 build1

Status: RESOLVED INCOMPLETE

(Release Engineering :: Release Automation, defect)

Description

[Nick Thomas [:nthomas] (UTC+12)]

... which caused issues for check permissions and antivirus when they detected temporary files from rsync. Both jobs were run on bm86 and there are two distinct requests, which suggests something happened in scheduler land.

Comment 1

[Nick Thomas [:nthomas] (UTC+12)]

Log from bm81 build_scheduler, excluding prioritizeBuilders:

# the last win32 l10n repacks are done, repack_complete scheduler gets prodded
2014-10-27 07:50:04-0700 [-] AggregatingScheduler(release-mozilla-release-firefox_deliverables_ready) <id=209638392>: new builds: ((u'release-mozilla-release-linux_partner_repack', 53568396L, 1414416696L),) since 1414416696
2014-10-27 07:50:04-0700 [-] AggregatingScheduler(release-mozilla-release-win32_repack_complete) <id=228833256>: new builds: ((u'release-mozilla-release-win32_repack_2/10', 53568312L, 1414421400L), (u'release-mozilla-release-win32_repack_4/10', 53568314L, 1414421164L), (u
'release-mozilla-release-win32_repack_9/10', 53568319L, 1414421147L)) since 1414421164
2014-10-27 07:50:04-0700 [-] AggregatingScheduler(release-mozilla-release-win32_repack_complete) <id=228833256>: new buildset: branch=releases/mozilla-release, ssid=9032578, builders: release-mozilla-release-win32_repack_complete
2014-10-27 07:50:04-0700 [-] AggregatingScheduler(release-mozilla-release-win32_repack_complete) <id=228833256>: get_initial_state()

# some noise, trigger win32_partner_repack
2014-10-27 07:50:05-0700 [-] AggregatingScheduler(release-mozilla-release-firefox_signing_done) <id=209637600>: new builds: ((u'release-mozilla-release-linux_repack_complete', 53568395L, 1414413971L),) since 1414413971
2014-10-27 07:50:06-0700 [Broker,82358,10.26.52.45] perspective_addChange called
2014-10-27 07:50:06-0700 [Broker,82358,10.26.52.45] adding change, who sendchange-unittest, 2 files, rev=36055c9984b5, branch=maple-linux64_gecko-debug-unittest, repository=, comments Fix cache mochitest., category None, project
2014-10-27 07:50:08-0700 [-] AggregatingScheduler(release-mozilla-release-win32_firefox_l10n_done) <id=209641056>: new builds: ((u'release-mozilla-release-win32_repack_complete', 53573108L, 1414421409L),) since 1414394877.08
2014-10-27 07:50:08-0700 [-] AggregatingScheduler(release-mozilla-release-win32_firefox_l10n_done) <id=209641056>: new buildset: branch=releases/mozilla-release, ssid=9032580, builders: release-mozilla-release-win32_partner_repack
2014-10-27 07:50:08-0700 [-] AggregatingScheduler(release-mozilla-release-win32_firefox_l10n_done) <id=209641056>: get_initial_state()

# some more noise, the trigger win32_partner_repack again
2014-10-27 07:50:09-0700 [-] <HgPoller for https://hg.mozilla.org/projects/fig>: polling failed, result Getting https://hg.mozilla.org/projects/fig/json-pushes?full=1 took longer than 30 seconds.
2014-10-27 07:50:09-0700 [-] Traceback (most recent call last):
2014-10-27 07:50:09-0700 [-] Failure: twisted.internet.defer.TimeoutError: Getting https://hg.mozilla.org/projects/fig/json-pushes?full=1 took longer than 30 seconds.
2014-10-27 07:50:09-0700 [HTTPPageGetter,client] Stopping factory <HTTPClientFactory: https://hg.mozilla.org/projects/fig/json-pushes?full=1>
2014-10-27 07:50:09-0700 [-] AggregatingScheduler(release-mozilla-release-firefox_deliverables_ready) <id=209638392>: new builds: ((u'release-mozilla-release-linux_partner_repack', 53568396L, 1414416696L), (u'release-mozilla-release-win32_repack_complete', 53573108L, 1414421409L)) since 1414416696
2014-10-27 07:50:10-0700 [-] AggregatingScheduler(release-mozilla-release-firefox_signing_done) <id=209637600>: new builds: ((u'release-mozilla-release-linux_repack_complete', 53568395L, 1414413971L), (u'release-mozilla-release-win32_repack_complete', 53573108L, 1414421409L)) since 1414413971
2014-10-27 07:50:10-0700 [-] AggregatingScheduler(release-mozilla-release-firefox_signing_done) <id=209637600>: new buildset: branch=releases/mozilla-release, ssid=9032581, builders: release-mozilla-release-updates
2014-10-27 07:50:10-0700 [-] AggregatingScheduler(release-mozilla-release-firefox_signing_done) <id=209637600>: get_initial_state()

No sign of any reconfig. rail, you're the scheduling guru, any thoughts on this ?

Comment 2

[Rail Aliiev [:rail]]

So, I found 2 entries caused this:

1)
2014-10-27 07:50:08-0700 [-] AggregatingScheduler(release-mozilla-release-win32_firefox_l10n_done) <id=209641056>: new builds: ((u'release-mozilla-release-win32_repack_complete' , 53573108L, 1414421409L),) since 1414394877.08
2014-10-27 07:50:08-0700 [-] AggregatingScheduler(release-mozilla-release-win32_firefox_l10n_done) <id=209641056>: new buildset: branch=releases/mozilla-release, ssid=9032580, builders: release-mozilla-release-win32_partner_repack


2)
2014-10-27 07:50:13-0700 [-] AggregatingScheduler(release-mozilla-release-win32_firefox_l10n_done) <id=209641056>: new builds: ((u'release-mozilla-release-win32_repack_complete' , 53573108L, 1414421409L),) since 1414421409
2014-10-27 07:50:13-0700 [-] AggregatingScheduler(release-mozilla-release-win32_firefox_l10n_done) <id=209641056>: new buildset: branch=releases/mozilla-release, ssid=9032582, builders: release-mozilla-release-win32_partner_repack 

We spend 2-3 hours with bhearsum trying to find where it may coming from. No luck even after digging into the buildbot, twisted and mysqldb code. :/

We may need to add more logging to figure out what is going on here.

Comment 3

[Rail Aliiev [:rail]]

Attachment: moar_logging.diff

Comment 4

[Nick Thomas [:nthomas] (UTC+12)]

Comment on attachment 8524883 [details] [diff] [review]
moar_logging.diff

Thanks for looking into this. Smelling a bit like a db gremlin.

Comment 5

[Rail Aliiev [:rail]]

Comment on attachment 8524883 [details] [diff] [review]
moar_logging.diff

https://hg.mozilla.org/build/buildbotcustom/rev/7488410fce9b

Comment 6

[Release Engineering SlaveAPI Service]

In production: https://hg.mozilla.org/build/buildbotcustom/rev/7488410fce9b

Comment 7

[Rail Aliiev [:rail]]

I haven't seen this for ages.