974094 - Stale filehandles on hgweb[1-8].dmz.scl3 hosts

Status: RESOLVED INVALID

(Infrastructure & Operations :: Storage, task)

Description

[Ben Kero [:bkero]]

Responding to reports about HTTP 500s from the release engineering folks I've encountered some reports of stale file handles in the httpd logs. Specifically:

hgweb2.dmz.scl3.mozilla.com: 
[Tue Feb 18 04:59:40 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 05:45:25 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 06:00:42 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 07:12:36 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 07:18:47 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/releases/mozilla-aurora/.hg/store/phaseroots'
[Tue Feb 18 10:06:59 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 10:42:00 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 11:35:08 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/projects/oak/.hg/store/phaseroots'
[Tue Feb 18 11:57:07 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 12:21:08 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/b2g-inbound/.hg/store/phaseroots'
hgweb3.dmz.scl3.mozilla.com: 
[Tue Feb 18 04:07:02 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 04:21:09 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 05:04:21 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 05:41:10 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/comm-central/.hg/store/phaseroots'
[Tue Feb 18 06:03:13 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/gaia-central/.hg/phaseroots'
[Tue Feb 18 06:35:44 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 08:09:09 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/fx-team/.hg/store/phaseroots'
[Tue Feb 18 10:07:03 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 10:31:51 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 11:18:19 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 11:54:36 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/releases/mozilla-beta/.hg/store/phaseroots'
[Tue Feb 18 12:04:09 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 12:21:12 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/b2g-inbound/.hg/store/phaseroots'
[Tue Feb 18 12:37:25 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try-comm-central/.hg/store/phaseroots'
hgweb4.dmz.scl3.mozilla.com: 
[Tue Feb 18 03:43:55 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/gaia-central/.hg/phaseroots'
[Tue Feb 18 04:42:42 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 05:25:08 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/gaia-central/.hg/phaseroots'
[Tue Feb 18 07:30:37 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 07:38:08 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/releases/mozilla-b2g26_v1_2/.hg/store/phaseroots'
[Tue Feb 18 08:11:13 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/b2g-inbound/.hg/store/phaseroots'
[Tue Feb 18 09:49:25 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 11:48:18 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 12:30:48 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 12:35:57 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/b2g-inbound/.hg/store/phaseroots'
[Tue Feb 18 12:37:20 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try-comm-central/.hg/store/phaseroots'
[Tue Feb 18 13:09:42 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
hgweb5.dmz.scl3.mozilla.com: 
[Tue Feb 18 03:08:03 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 03:50:16 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/fx-team/.hg/store/phaseroots'
[Tue Feb 18 04:07:06 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 04:54:22 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 05:24:56 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/gaia-central/.hg/phaseroots'
[Tue Feb 18 07:06:36 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/projects/gum/.hg/store/phaseroots'
[Tue Feb 18 08:21:58 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/gaia-central/.hg/phaseroots'
[Tue Feb 18 09:49:37 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 10:07:04 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 12:04:16 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 12:48:46 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
hgweb6.dmz.scl3.mozilla.com: 
[Tue Feb 18 03:51:47 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/b2g-inbound/.hg/store/phaseroots'
[Tue Feb 18 05:58:34 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 06:22:15 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 06:35:54 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 06:54:28 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/fx-team/.hg/store/phaseroots'
[Tue Feb 18 06:59:12 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 07:00:53 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 07:30:41 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 08:11:24 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/b2g-inbound/.hg/store/phaseroots'
[Tue Feb 18 08:22:06 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/gaia-central/.hg/phaseroots'
[Tue Feb 18 08:42:58 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 09:01:39 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 09:56:31 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/releases/mozilla-aurora/.hg/store/phaseroots'
[Tue Feb 18 10:20:06 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 11:18:43 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 11:20:33 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 11:57:07 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 12:37:29 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try-comm-central/.hg/store/phaseroots'
[Tue Feb 18 13:04:56 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
hgweb7.dmz.scl3.mozilla.com: 
[Tue Feb 18 04:42:41 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 04:59:43 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 06:20:21 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/fx-team/.hg/store/phaseroots'
[Tue Feb 18 06:29:45 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 06:35:58 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 07:17:32 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/releases/mozilla-beta/.hg/store/phaseroots'
[Tue Feb 18 09:41:50 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 09:53:01 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 10:07:08 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 10:07:08 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/projects/gum/.hg/store/phaseroots'
[Tue Feb 18 10:20:17 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 11:08:30 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/users/mconley_mozilla.com/faster-transitions/.hg/store/phaseroots'
[Tue Feb 18 11:57:03 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 11:58:03 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/releases/mozilla-beta/.hg/store/phaseroots'
[Tue Feb 18 12:25:08 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 13:08:50 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/releases/mozilla-aurora/.hg/store/phaseroots'
hgweb8.dmz.scl3.mozilla.com: 
[Tue Feb 18 05:25:02 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/gaia-central/.hg/phaseroots'
[Tue Feb 18 05:58:33 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 06:01:16 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/mozilla-inbound/.hg/store/phaseroots'
[Tue Feb 18 06:15:51 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/gaia-central/.hg/phaseroots'
[Tue Feb 18 06:51:07 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/b2g-inbound/.hg/store/phaseroots'
[Tue Feb 18 06:53:27 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/releases/mozilla-aurora/.hg/store/phaseroots'
[Tue Feb 18 07:01:05 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/mozilla-central/.hg/store/phaseroots'
[Tue Feb 18 08:11:16 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/integration/b2g-inbound/.hg/store/phaseroots'
[Tue Feb 18 09:57:50 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'
[Tue Feb 18 11:03:03 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/releases/gaia-l10n/v1_3/sr-Latn/.hg/store/phaseroots'
[Tue Feb 18 13:09:48 2014] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/try/.hg/store/phaseroots'

The oldest log I can find about the behavior is:
[Mon Jun 03 05:41:03 2013] [error] [client 10.22.74.212] OSError: [Errno 116] Stale file handle: '/repo/hg/mozilla/comm-central/.hg/store/phaseroots'

Note that these are just the oldest logs on the webheads, and the error could have been occurring before that date.

The mount in question is 10.22.74.20:/hg/hg_qtree

Comment 1

[Greg Cox [:gcox]]

hg was moved from the old filer to the new one in 951323 (2014-01-11), so, this on both sides of the move.

Picking on the last file:

[e-mail]3:~$ date ; stat /repo/hg/mozilla/try/.hg/store/phaseroots|tail -3
Tue Feb 18 13:34:05 PST 2014
Access: 2014-02-18 13:31:14.134866000 -0800
Modify: 2014-02-18 13:31:14.141877000 -0800
Change: 2014-02-18 13:31:14.141886000 -0800

While it's not a create-date, it does suggest that this is a file that got removed/added, and thus the Stale Filehandle is true.  I don't think these are problems, per se, in a high file-turnover world.  It looks like the app assuming the file is open, when it's not.

Other mount options, like noac or sync, could boost cache consistency, but as `man 5 nfs` notes: "Perfect cache coherence among disparate NFS clients is expensive to achieve."

Comment 2

[Ben Kero [:bkero]]

I remounted the volume with the 'sync' option several weeks ago to help prevent problems like this, although it seems not to have helped (much if at all).

Comment 3

[Greg Cox [:gcox]]

Mild correction, I misread the times and thus my conclusion didn't spring obviously from the premises I pasted, but, point here is those files are turning over regularly, into new inodes:

[e-mail]3:~$ date ; stat /repo/hg/mozilla/try/.hg/store/phaseroots | grep Inode
Tue Feb 18 13:55:47 PST 2014
Device: 13h/19d	Inode: 96099063    Links: 1
[e-mail]3:~$ date ; stat /repo/hg/mozilla/try/.hg/store/phaseroots |grep Inode
Tue Feb 18 14:04:01 PST 2014
Device: 13h/19d	Inode: 96099064    Links: 1


I don't think these errors mean anything evil.  The file going away/being recreated is something that the application appears to be asking for.  From what I understand hg wasn't built with nfs in mind, so that it has an open filehandle on a file it thinks it would control kinda doesn't surprise me, but I'm not sure what we could do about it if some hosts have chosen to hold the filehandle.

Comment 4

[Greg Cox [:gcox]]

If I'm mistaken we can reopen, but this feels like it's over.

Since hgweb's off NFS, this isn't really a thing anymore.  Even if it were, the files going away looks pretty expected from an app perspective, so that there's 'stale' errors popping up isn't really a surprise.  And there's not much from a storage perspective we can do about it, since the application was causing its own issue.