1038478 - releases/l10n/mozilla-beta/ repos are inconsistent across hgweb*

Status: RESOLVED FIXED

(Developer Services :: General, task)

Description

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

Two of our three android builds for 31.0b10 worked ok, but one failed to get rev 50b3a539bd85 from https://hg.mozilla.org/releases/l10n/mozilla-beta/ms/.

hgweb1/3/7 have it, 2/4/5/6/8 don't.

Comment 1

[Ben Kero [:bkero]]

While digging for the possible problem I found these errors:

on hgssh1:

Jul 14 15:39:11 hgssh1 repo-push.sh to hgweb6.dmz.scl3.mozilla.com releases/l10n/mozilla-beta/ms from ffxbld): remote: ssh_exchange_identification: Connection closed by remote host#015
Jul 14 15:39:11 hgssh1 repo-push.sh to hgweb6.dmz.scl3.mozilla.com releases/l10n/mozilla-beta/ms from ffxbld): abort: no suitable response from remote hg!

There were no relevant logs on hgweb6 (PAM error came later):

[[e-mail]3 log]# grep 15:39 secure messages|grep -v puppet
secure:Jul 13 15:39:05 hgweb6 sshd[6355]: Set /proc/self/oom_score_adj to 0
secure:Jul 13 15:39:05 hgweb6 sshd[6355]: Connection from 10.22.75.42 port 35459
secure:Jul 13 15:39:05 hgweb6 sshd[6356]: Connection closed by 10.22.75.42
secure:Jul 14 15:39:27 hgweb6 sudo: PAM unable to dlopen(/lib64/security/pam_fprintd.so): /lib64/security/pam_fprintd.so: cannot open shared object file: No such file or directory
secure:Jul 14 15:39:27 hgweb6 sudo: PAM adding faulty module: /lib64/security/pam_fprintd.so

Comment 2

[Ben Kero [:bkero]]

(the repository was synced out correctly when running the syncing script manually)

Comment 3

[Ben Kero [:bkero]]

Handing off to general dev services for whoever has time to investigate this

Comment 4

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

Thanks for the fix Ben.

Comment 5

[Kendall Libby [:fubar] (he/him)]

hgssh1.dmz.scl3# grep repo-push messages* | grep 'Connection closed by remote host' | wc -l
328

So, this has hit us 328 times in the last month, but we only noticed now. I have greatly mixed feelings about that. 

I've manually synced up everything; there were only a few outstanding repos. 

I think we have two paths from here:

1) figure out why the sync is failing - because it's all in the same DC, this has some merit, in case there are larger issues, but overall I feel this is a lower priority than..

2) make the sync process more robust - currently, it's just a bash for loop that runs logger and ssh (that dumps output to logger). at the very least, it's probably worth setting pipefail and check the return code for the ssh pipeline. ideal might be checking the output and attempting to re-run the push to failed nodes.

Comment 6

[Kendall Libby [:fubar] (he/him)]

Jul 18 09:54:07 hgssh1 repo-push.sh to hgweb6.dmz.scl3.mozilla.com build/buildbot-configs from [e-mail]): remote: ssh_exchange_identification: Connection closed by remote host#015
Jul 18 09:54:07 hgssh1 repo-push.sh to hgweb6.dmz.scl3.mozilla.com build/buildbot-configs from [e-mail]): abort: no suitable response from remote hg!
Jul 18 09:54:07 hgssh1 sshd[11734]: Connection from 10.22.74.212 port 14693
Jul 18 09:54:07 hgssh1 repo-push.sh to hgweb7.dmz.scl3.mozilla.com build/buildbot-configs from [e-mail]): remote: ssh_exchange_identification: Connection closed by remote host#015
Jul 18 09:54:07 hgssh1 repo-push.sh to hgweb7.dmz.scl3.mozilla.com build/buildbot-configs from [e-mail]): abort: no suitable response from remote hg!
Jul 18 09:54:07 hgssh1 repo-push.sh to hgweb5.dmz.scl3.mozilla.com build/buildbot-configs from [e-mail]): remote: ssh_exchange_identification: Connection closed by remote host#015
Jul 18 09:54:07 hgssh1 repo-push.sh to hgweb5.dmz.scl3.mozilla.com build/buildbot-configs from [e-mail]): abort: no suitable response from remote hg!
Jul 18 09:54:07 hgssh1 repo-push.sh to hgweb8.dmz.scl3.mozilla.com build/buildbot-configs from [e-mail]): remote: ssh_exchange_identification: Connection closed by remote host#015
Jul 18 09:54:07 hgssh1 repo-push.sh to hgweb8.dmz.scl3.mozilla.com build/buildbot-configs from [e-mail]): abort: no suitable response from remote hg!

Comment 7

[Kendall Libby [:fubar] (he/him)]

list of similar sync failures since the 15th;

Jul 16 11:05:14 hgweb3.dmz.scl3.mozilla.com users/mgervasini_mozilla.com/en-GB
Jul 16 11:06:48 hgweb6.dmz.scl3.mozilla.com try
Jul 16 18:09:40 hgweb7.dmz.scl3.mozilla.com try
Jul 16 18:09:40 hgweb8.dmz.scl3.mozilla.com try
Jul 16 18:09:40 hgweb3.dmz.scl3.mozilla.com try
Jul 17 21:10:30 hgweb4.dmz.scl3.mozilla.com releases/mozilla-aurora
Jul 17 23:27:10 hgweb6.dmz.scl3.mozilla.com releases/gaia-l10n/v1_3/zh-TW
Jul 17 23:30:31 hgweb8.dmz.scl3.mozilla.com releases/mozilla-aurora
Jul 18 09:54:07 hgweb6.dmz.scl3.mozilla.com build/buildbot-configs
Jul 18 09:54:07 hgweb7.dmz.scl3.mozilla.com build/buildbot-configs
Jul 18 09:54:07 hgweb5.dmz.scl3.mozilla.com build/buildbot-configs
Jul 18 09:54:07 hgweb8.dmz.scl3.mozilla.com build/buildbot-configs

Comment 8

[Kendall Libby [:fubar] (he/him)]

Attachment: updated repo-push.sh to better handle/report errors

Added ssh option 'ConnectionAttempts=3' to help with the ssh errors. Default is 1. The bitbucket thread discussing similar issues noted that an immediate retry usually (always?) got around the problem. (ssh options also moved to variable for easier reading)

Failing that... exit status of ssh now checked; on error, waits a second and then tries again, with additional logging. Because bash, this was turned into a function that we can background, while still checking return codes, etc. 

I can still elicit ssh errors, but it requires multiple simultaneous evocations. It's possible that they may still crop up, particularly on bigger/slower repos, but the connect attempts and retry should help with that.

Comment 9

[hwine]

Comment on attachment 8460548 [details]
updated repo-push.sh to better handle/report errors

This is better than what we have -- klibby's tests show that this does detect and log a class of ssh error which was "invisible" before.

Let's go with it for now.

Comment 10

[Ben Kero [:bkero]]

Comment on attachment 8460548 [details]
updated repo-push.sh to better handle/report errors

lgtm

Comment 11

[Lonnen :lonnen]

Comment on attachment 8460548 [details]
updated repo-push.sh to better handle/report errors

Lines {8,9} and {14,15} could DRY out a little, but this will do the job.

Comment 12

[Kendall Libby [:fubar] (he/him)]

Added "-o ServerAliveInterval=5" to ssh options after conversation in #vcs. Script committed to puppet and is in production.

Comment 13

[hwine]

update: no new out-of-sync issues reported since deployment

Comment 14

[Kendall Libby [:fubar] (he/him)]

checked all repos updated since Jul 1, and we're still all good.

Comment 15

[Kendall Libby [:fubar] (he/him)]

we missed adding the ssh ServerAlive* and ConnectionAttempts to the hg user on hgweb* (for hgweb*->hg.m.o:22 pulls), and ran into a hangup with hgweb6 pulling a try update.

added in r91124.

Comment 16

[Pete Moore [:pmoore][:pete]]

See also https://bugzilla.mozilla.org/show_bug.cgi?id=1036998#c2 (comments 2 - 4)

Comment 17

[Kendall Libby [:fubar] (he/him)]

high load on the hg web heads this morning caused issues, e.g.:

Jul 31 04:39:00 hgssh1 repo-push.sh[17062] integration/gaia-central to hgweb1.dmz.scl3.mozilla.com for [e-mail]: Connection timed out during banner exchange#015
Jul 31 04:39:04 hgssh1 repo-push.sh[17062] retry integration/gaia-central to hgweb3.dmz.scl3.mozilla.com for [e-mail]: Connection timed out during banner exchange#015
Jul 31 04:39:04 hgssh1 repo-push.sh[17062] retry integration/gaia-central to hgweb4.dmz.scl3.mozilla.com for [e-mail]: Connection timed out during banner exchange#015


integration/gaia-central, integration/gaia, try-comm-central, and one user repo were affected. 

I've increased the ConnectTimeout in repo-push.sh from 3s to 10s.

Comment 18

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

We had another case with https://hg.mozilla.org/releases/l10n/mozilla-beta/si in the Firefox 32.0b4 release. The build machine did a fresh clone then tried to update to the tag FIREFOX_32_0b4_RELEASE. This failed because 23eeb52560a7 was the last changeset in the repo, ie it's missing d6bdca917766.

Comment 19

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

Same story for https://hg.mozilla.org/releases/l10n/mozilla-beta/nn-NO

Comment 20

[Ben Kero [:bkero]]

Same events in the logs:

Aug  4 16:27:27 hgssh1 repo-push.sh[28452] releases/l10n/mozilla-beta/si to hgweb3.dmz.scl3.mozilla.com for ffxbld: remote: ssh_exchange_identification: Connection closed by remote host#015
Aug  4 16:27:27 hgssh1 repo-push.sh[28452] releases/l10n/mozilla-beta/si to hgweb3.dmz.scl3.mozilla.com for ffxbld: abort: no suitable response from remote hg!

Comment 21

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

https://hg.mozilla.org/releases/l10n/mozilla-beta/kn today, do we have any more ideas about tweaking the config ? This release automation seems to tickle this bug every beta.

Comment 22

[Kendall Libby [:fubar] (he/him)]

Repos resynced. If this is blocking stuff overnight, let the MOC know and they can use the docs at https://mana.mozilla.org/wiki/display/SYSADMIN/Mercurial+-+Common+Repository+Operations#Mercurial-CommonRepositoryOperations-Verifyingandre-syncingwebheads to fix it.

Need to go and look through the logs to see where these syncs fell apart. I know we can make a few more tweaks in one part of the process, but I'm not sure we've seen it break there yet.

Comment 23

[Kendall Libby [:fubar] (he/him)]

The zeus connection mgmt settings for the hgssh pool were kinda low - 4s connect timeout and 30s no-reply timeout. Increased to 30s and 45s. 

mirror-pull still needs to be changed to retry pulls on failure. Also, we may have glanced over it, but we currently set ConnectionAttempts=3 for ssh, which is actually only three attempts one second apart, rather than 3*N seconds. We might also want to increase the ConnectTimeout to match zeus; currently set to 15s.

Comment 24

[Kendall Libby [:fubar] (he/him)]

Attachment: add retries to mirror-pull

unherped my derp and found the easy way to have mirror-pull retry pulls/clones and scp's of pushlog. also makes the pushlog swap contingent on scp's success.

Comment 25

[Ben Kero [:bkero]]

Comment on attachment 8472534 [details] [diff] [review]
add retries to mirror-pull

lgtm as long as the retry function is also fetching the commands after && and honoring the redirects

Comment 26

[Kendall Libby [:fubar] (he/him)]

it does if I put quotes around it. thx.

Comment 27

[Kendall Libby [:fubar] (he/him)]

At least a dozen failed syncs over the course of last night. Commited changes to mirror-pull in r92016. Rolling out to hgweb heads now.

Comment 28

[Kendall Libby [:fubar] (he/him)]

success!

Aug 14 07:00:43 hgssh1 repo-push.sh[17266] -e try to hgweb9.dmz.scl3.mozilla.com for [e-mail]: remote: ssh_exchange_identification: Connection closed by remote host#015
Aug 14 07:00:45 hgssh1 repo-push.sh[17266] -e try to hgweb9.dmz.scl3.mozilla.com for [e-mail]: retrying hg pull --config hooks.pretxnchangegroup.z_linearhistory= --config hooks.pretxnchangegroup.z_loghistory= --config trusted.users=root,hg --config paths.default=ssh://hg.mozilla.org/try

still unknown what's causing the intermittent ssh failures on pull, though.

Comment 29

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

We didn't have any problems with 32.0b7 today, there was much rejoicing!

Comment 30

[Kendall Libby [:fubar] (he/him)]

Increased sshd's MaxSessions and MaxStartups to 50 yesterday after continued failures and (successful) retries. No unexpected issues since.

Comment 31

[hwine]

Comment on attachment 8472534 [details] [diff] [review]
add retries to mirror-pull

Review of attachment 8472534 [details] [diff] [review]:
-----------------------------------------------------------------

::: mirror-pull.erb
@@ +115,5 @@
>  
>  cd $REPO_TARGET || die "$REPO_TARGET does not exist, cannot create repositories there"
>  
> +retry() {
> +    local _cmd=$*

nit - _cmd="$@" catches some cases that show up as more mac/windows folks name things :)

But functionally equivalent for sane (old school) unix ;)

Comment 32

[Kendall Libby [:fubar] (he/him)]

There was one mis-sync during one of the last super high load episodes, but nothing since. Calling it good.