NFS を使っていて .nfsXXXX みたいなファイルが生成されたときの対処方法

本業で Oracle 10g RAC を使っているのですが共有ディスクには NetApp Filer を使ってます。でもって Filer の接続方法としては DAS/SAN ではなくより簡易な NFS を使ってます。とっても便利な NetApp Filer の snapshot 機能。これを一度使ったらもう他のストレージには戻れません。と言うわけで NetApp Filer お奨めです。NetApp ファイラーを使用した超高速バックアップ&リカバリ なんかも参考にどうぞ。

ってことを書きたかったわけではなく障害なんてのは予期せず発生するものです。ちょっと前の話ですが、バッチ処理で Oracle のアーカイブログファイルが予想外に大量に生成されてディスクが満杯になってしまいました。でもって障害通知メールでそのことに気がつきあわてて不要なログファイルを削除。

とまぁ通常のディスクならこれで問題ないわけですが NetApp Filer の snapshot 機能を使っているので削除しても実体は削除されず snapshot として残ります。以前書いた図なのですが、

ディスク容量が既に空き容量0のため、2の状態に移行できないわけです。結果今まで見たこともない .nfsXXXX という謎のファイルが大量に生成されてしましました。

[root@testdb02 db_arc2]# ls -la
合計 1350364
    64 drwxrwxrwx   3 root   root      8192  3月 10 19:48 .
     2 drwxr-xr-x  31 root   root      4096  2月  5 14:21 ..
105970 -rw-rw----   1 oracle dba  208080384  3月  8 21:19 .nfs0000000000019df200000001
105971 -rw-rw----   1 oracle dba  208080384  3月  8 21:19 .nfs0000000000019df300000003
105972 -rw-rw----   1 oracle dba  208080384  3月  8 21:20 .nfs0000000000019df400000005
105973 -rw-rw----   1 oracle dba  208080384  3月  8 21:20 .nfs0000000000019df500000007
105974 -rw-rw----   1 oracle dba  208080384  3月  8 21:20 .nfs0000000000019df60000000a
    67 drwxrwxrwx   4 root   root      4096  3月 10 05:01 .snapshot
105982 -rw-rw----   1 oracle dba  202560512  3月 10 00:01 testdb_1_1831_585074576.arc
105966 -rw-rw----   1 oracle dba  202743808  3月 10 09:30 testdb_1_1832_585074576.arc
105967 -rw-rw----   1 oracle dba  202632704  3月 10 12:13 testdb_1_1833_585074576.arc
・・・snip・・・

さてどうしたものか・・・ネットで情報を調べてもなかなか出てこなかったので Linux の Kernel 読んだりいろいろ調べてこうすれば消えましたという解決方法について話します。

- スポンサーリンク -

NetApp Filet をいったん忘れて nfs に話を絞った解決方法の結論から。

.nfsXXXX ってファイルは nfs の仕様上、予期せぬ動作時に発生しうる一時ファイルで unlink されたはずのファイルに対して nfs-client がファイルディスクリプタを掴んだままの状態になってしまった場合に、元のファイル名を一時的に .nfsXXXX 形式のファイル名にリネームしたものになります。.nfsXXXX を消すには nfs-client 側でファイルディスクリプタを掴んだままになっているプロセスを終了させることで nfs-server 側で一定のタイミングで自動的に消去されます。

つまり .nfsXXXX を使用中のプロセスを調べてそれを kill すれば自動的に .nfsXXXX は消滅します。
逆に明示的に rm -rf .nfsXXXX とかやっても使用中なので消せないってエラーがでます。

rm: remove 通常ファイル `.nfs00000000000223e300000017'? y
rm: cannot remove `.nfs00000000000223e300000017': デバイスもしくはリソースがビジー状態です


さて、以下は自分向けの備忘録含めて作業手順です。

1. まずは NetApp Filer からファイルを削除可能とするために一時的に snapshot 機能を off にします。

filer へログインして過去のスナップショットを削除します。

rsh -l root nas01 snap delete vol2 old1
rsh -l root nas02 snap delete vol3 old1

2. これでディスク容量に空きが出るので .nfsXXXX の削除を行う。

ファイルディスクリプタを掴んでいるプロセスとかをいちいち調べるのが面倒なのでスクリプトを書きました。fuser コマンドでファイルを使用しているプロセスを割り出してそのプロセスのユーザも調べるってシロモノです。今回の調査対象ファイルは、/db_arc1/.nfsXXXX と /db_arc2/.nfsXXXX たちです。

my @files = ( glob('/db_arc1/.*'), glob('/db_arc2/.*') );

my %pids;
my %puser;
for (@files) {
    next unless ( /\.nfs/ );
    my $msg = `fuser $_`;
    my ( $target, $pid ) = split( ':', $msg );
    $pid =~ s/\D//msxg;
    push @{$pids{$pid}}, $target;
}
for my $pid ( keys %pids ) {
    my $msg = `ps aux|grep $pid`;
    my @tmp = split("\n", $msg);
    my ($user,$pname) = $tmp[0] =~ /^(.+?)\s+$pid.+\s(.+?)$/msx;
    ($puser{$pid}) = $user;
    print qq{user: $puser{$pid}\nprocess: $pid : $pname\n};
    print qq{  file: $_\n} for ( @{$pids{$pid}} );
}

こいつを実行するとこんな感じの結果になりました。

user: oracle
process: 8054 : ora_arc1_testdb2
  file: /db_arc1/.nfs00000000000223e400000018
  file: /db_arc1/.nfs00000000000223e500000019
  file: /db_arc1/.nfs00000000000223e60000001a
・・・snip・・・
user: oracle
process: 8052 : ora_arc0_testdb2
  file: /db_arc1/.nfs00000000000223e300000017
  file: /db_arc1/.nfs00000000000223e80000001c
  file: /db_arc1/.nfs00000000000223e90000001d
・・・snip・・・

えーっとまぁ上記の場合は Oracle のアーカイブプロセスがファイルを掴みっぱなしになっているというわけです。ちなみにアラートログにも大量にエラーが出力されてました。

WL=2:アラートログメッセージが更新されました ORA-19502: ファイル"/db_arc2/testdb_2_2325_585074576.arc"の書込みエラーが発生しました。ブロック番号14337(ブロックサイズ=512) [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-27072: ファイルI/Oエラーが発生しました。 [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-19502: ファイル"/db_arc2/testdb_2_2325_585074576.arc"の書込みエラーが発生しました。ブロック番号14337(ブロックサイズ=512) [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-19502: ファイル"/db_arc1/testdb_2_2325_585074576.arc"の書込みエラーが発生しました。ブロック番号14337(ブロックサイズ=512) [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-27072: ファイルI/Oエラーが発生しました。 [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-19502: ファイル"/db_arc1/testdb_2_2325_585074576.arc"の書込みエラーが発生しました。ブロック番号14337(ブロックサイズ=512) [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-16038: ログ3、順序番号2325をアーカイブできません。 [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-19502: ファイル""の書込みエラーが発生しました。ブロック番号(ブロックサイズ=) [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-00312: オンライン・ログ3 スレッド2: '/db1/oradata/testdb/redo2/testdbredo1_1_2.dbf' [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-00312: オンライン・ログ3 スレッド2: '/db2/oradata/testdb/redo2/testdbredo1_2_2.dbf' [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-16038: ログ3、順序番号2325をアーカイブできません。 [Mail Notified]
WL=2:アラートログメッセージが更新されました ORA-19502: ファイル""の書込みエラーが発生しました。ブロック番号(ブロックサイズ=) [Mail Notified]
・・・snip・・・

幸い Oracle のアーカイブプロセスは PMON が自動管理しているプロセスになるので kill しちゃえば勝手に再起動されるのである意味安心して kill できます。この辺はまた詳しく。取りあえず作業的にはこんな感じ。

[root@testdb02 ~]# ps aux|grep ora_arc
oracle    8052  0.0  0.5 1951704 32500 ?     Ss   Feb05   1:02 ora_arc0_testdb2
oracle    8054  0.0  0.5 1951704 32900 ?     Ss   Feb05   1:28 ora_arc1_testdb2

kill -9 8052
kill -9 8054

[root@testdb02 ~]# ps aux|grep ora_arc
oracle    1860  0.0  0.2 1951700 17676 ?     Ss   16:26   0:00 ora_arc0_testdb2
oracle   25496  0.4  0.2 1951700 17628 ?     Ss   16:40   0:00 ora_arc1_testdb2

と言うわけで無事に再起動されたことが確認できました。より詳しく知りたいならアラートログでも見ればOKですが今回は割愛します。

さて、これで .nfsXXXX は勝手に消滅していくはずです。温かく見守ります。数十秒後・・・こんな状態に。一瞬ビビリまくる。

[root@testdb02 db_arc1]# ls -la
合計 3310924
drwxrwxrwx   3 root   root      8192  3月 11 16:40 .
drwxr-xr-x  31 root   root      4096  2月  5 14:21 ..
?---------   ? ?      ?            ?             ? .nfs00000000000223e400000018
?---------   ? ?      ?            ?             ? .nfs00000000000223e500000019
?---------   ? ?      ?            ?             ? .nfs00000000000223e60000001a
?---------   ? ?      ?            ?             ? .nfs00000000000223e70000001b
・・・snip・・・

さらに数秒後・・・正常状態に戻りましたーーー!!!

[root@testdb02 db_arc1]# ls -la
合計 3310924
drwxrwxrwx   3 root   root      8192  3月 11 16:40 .
drwxr-xr-x  31 root   root      4096  2月  5 14:21 ..
drwxrwxrwx   4 root   root      4096  3月 11 05:01 .snapshot
-rw-r--r--   1 root   root       563  3月 10 19:13 080310_fuser.pl
-rw-rw----   1 oracle dba  202560512  3月 11 00:01 testdb_1_1838_585074576.arc
-rw-rw----   1 oracle dba  207775744  3月 11 00:05 testdb_1_1839_585074576.arc
-rw-rw----   1 oracle dba  202560512  3月 11 05:51 testdb_1_1840_585074576.arc
・・・snip・・・

無事に .nfsXXXX は消えていきました。えーっとどうせなのでメモった深追いも中途半端ながら書きつづっておきます。

3. 最後に filet の snapshot を復活しておく

rsh -l root nas01 snap delete vol2 new
rsh -l root nas01 snap create vol2 new

応急処置おしまい。


.nfsXXXXについて深追い2 :: NetApp トラブルシューティングから

http://www.virtual.com/whitepapers/NetApp_NFS_Background.pdf より抜粋。

There are drawbacks to the stateless protocol. First, the semantics of the local filesystem imply state.
When files are unlinked, they continue to be accessible until the last reference to them is closed.
Because NFS knows neither which files are open on clients nor when those files are closed, it cannot properly know when to free file space.
As a result, it always frees the space at the time of the unlink of the last name to the file.
Clients that want to preserve the freeing-on-lastclose semantics convert unlink's of open files to renames to obscure names on the server.
The names are of the form .nfsAxxxx4.4, where the xxxx is replaced with the hexadecimal value of the process identifier, and the A is successively incremented until an unused name is found.
When the last close is done on the client, the client sends an unlink of the obscure filename to the server.
This heuristic works for file access on only a single client; if one client has the file open and another client removes the file, the file will still disappear from the first client at the time of the remove.
Other stateful semantics include the advisory locking described in Section 7.5.
The locking semantics cannot be handled by the NFS protocol. On most systems, they are handled by a separate lock manager; the 4.4BSD version of NFS does not implement them at all.

えーっと・・・英語苦手なんですが・・・怪しげな要約。

nfs のステートレスなプロトコルが問題で、nfs サーバ側ではどのファイルがクライアントで開かれていて、またそのファイルがいつ閉じられるかを知り得ないので、いつファイルスペースを解放して良いのかを適切に判断できません。ファイルスペースを解放しようとしたファイルに対してクライアントがアクセスを保持し続けようとした場合には、ファイル名を .nfsAxxxx4.4 形式にリネームして保持し続けます。ファイル名は .nfsAxxxx4.4 というユニークな名前になるように付与され、プロセス識別子を16 進値で表したものを利用して定義します。
また nfs プロトコルはロックを扱うことができないため、ほとんどのシステムでは個別のロックマネージャ
によって扱われます。ちなみに、BSD 4.4 の nfs では実装されてません。


FreeBSD と Linux でかなり処理の仕方が違うようでして、取りあえずどちらのソースも見たのですが、今回のファイルの命名規則からして Linux のソースが該当するようです。というか .nfsXXXX は nfs-client が生成するものなので nfs-client を使っているサーバが RHEL 4 なので Linux のソースを見るのが当たり前か。。。ってわけで kernel のソースを見てみました。

linux-2.6.9/fs/nfs/dir.c

static int nfs_sillyrename(struct inode *dir, struct dentry *dentry)
{
	static unsigned int sillycounter;
	const int      i_inosize  = sizeof(dir->i_ino)*2;
	const int      countersize = sizeof(sillycounter)*2;
	const int      slen       = strlen(".nfs") + i_inosize + countersize;
	char           silly[slen+1];
	struct qstr    qsilly;
	struct dentry *sdentry;
	int            error = -EIO;

	dfprintk(VFS, "NFS: silly-rename(%s/%s, ct=%d)\n",
		dentry->d_parent->d_name.name, dentry->d_name.name, 
		atomic_read(&dentry->d_count));

#ifdef NFS_PARANOIA
if (!dentry->d_inode)
printk("NFS: silly-renaming %s/%s, negative dentry??\n",
dentry->d_parent->d_name.name, dentry->d_name.name);
#endif
	/*
	 * We don't allow a dentry to be silly-renamed twice.
	 */
	error = -EBUSY;
	if (dentry->d_flags & DCACHE_NFSFS_RENAMED)
		goto out;

	sprintf(silly, ".nfs%*.*lx",
		i_inosize, i_inosize, dentry->d_inode->i_ino);

	sdentry = NULL;
	do {
		char *suffix = silly + slen - countersize;

		dput(sdentry);
		sillycounter++;
		sprintf(suffix, "%*.*x", countersize, countersize, sillycounter);

		dfprintk(VFS, "trying to rename %s to %s\n",
			 dentry->d_name.name, silly);
		
		sdentry = lookup_one_len(silly, dentry->d_parent, slen);
		/*
		 * N.B. Better to return EBUSY here ... it could be
		 * dangerous to delete the file while it's in use.
		 */
		if (IS_ERR(sdentry))
			goto out;
	} while(sdentry->d_inode != NULL); /* need negative lookup */

	qsilly.name = silly;
	qsilly.len  = strlen(silly);
	nfs_begin_data_update(dir);
	if (dentry->d_inode) {
		nfs_begin_data_update(dentry->d_inode);
		error = NFS_PROTO(dir)->rename(dir, &dentry->d_name,
				dir, &qsilly);
		nfs_end_data_update(dentry->d_inode);
	} else
		error = NFS_PROTO(dir)->rename(dir, &dentry->d_name,
				dir, &qsilly);
	nfs_end_data_update(dir);
	if (!error) {
		nfs_renew_times(dentry);
		nfs_set_verifier(dentry, nfs_save_change_attribute(dir));
		d_move(dentry, sdentry);
		error = nfs_async_unlink(dentry);
 		/* If we return 0 we don't unlink */
	}
	dput(sdentry);
out:
	return error;
}



/*  We do silly rename. In case sillyrename() returns -EBUSY, the inode
 *  belongs to an active ".nfs..." file and we return -EBUSY.
 *
 *  If sillyrename() returns 0, we do nothing, otherwise we unlink.
 */
static int nfs_unlink(struct inode *dir, struct dentry *dentry)
{
	int error;
	int need_rehash = 0;

	dfprintk(VFS, "NFS: unlink(%s/%ld, %s)\n", dir->i_sb->s_id,
		dir->i_ino, dentry->d_name.name);

	lock_kernel();
	spin_lock(&dcache_lock);
	spin_lock(&dentry->d_lock);
	if (atomic_read(&dentry->d_count) > 1) {
		spin_unlock(&dentry->d_lock);
		spin_unlock(&dcache_lock);
		error = nfs_sillyrename(dir, dentry);
		unlock_kernel();
		return error;
	}
	if (!d_unhashed(dentry)) {
		__d_drop(dentry);
		need_rehash = 1;
	}
	spin_unlock(&dentry->d_lock);
	spin_unlock(&dcache_lock);
	error = nfs_safe_remove(dentry);
	if (!error) {
		nfs_renew_times(dentry);
		nfs_set_verifier(dentry, nfs_save_change_attribute(dir));
	} else if (need_rehash)
		d_rehash(dentry);
	unlock_kernel();
	return error;
}

nfs_unlink() でファイルを削除する際にビジー状態の時に nfs_sillyrename() を call してファイル名を変更しています。なんだか nfs をいろいろと追いかけたのですが難解すぎて力尽きてそのまま放置状態です。解析はココまでしかすすんでません。


ってかこんなマイナーなエントリ役にたつんかいな?と思いつつも1人くらいには役に立つかも。ってか未来の自分??と思いつつ書き残しました。

- スポンサーリンク -