NFS を使っていて .nfsXXXX みたいなファイルが生成されたときの対処方法
本業で Oracle 10g RAC を使っているのですが共有ディスクには NetApp Filer を使ってます。でもって Filer の接続方法としては DAS/SAN ではなくより簡易な NFS を使ってます。とっても便利な NetApp Filer の snapshot 機能。これを一度使ったらもう他のストレージには戻れません。と言うわけで NetApp Filer お奨めです。NetApp ファイラーを使用した超高速バックアップ＆リカバリ なんかも参考にどうぞ。
ってことを書きたかったわけではなく障害なんてのは予期せず発生するものです。ちょっと前の話ですが、バッチ処理で Oracle のアーカイブログファイルが予想外に大量に生成されてディスクが満杯になってしまいました。でもって障害通知メールでそのことに気がつきあわてて不要なログファイルを削除。
とまぁ通常のディスクならこれで問題ないわけですが NetApp Filer の snapshot 機能を使っているので削除しても実体は削除されず snapshot として残ります。以前書いた図なのですが、
ディスク容量が既に空き容量０のため、２の状態に移行できないわけです。結果今まで見たこともない .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: 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
と言うわけで無事に再起動されたことが確認できました。より詳しく知りたいならアラートログでも見ればＯＫですが今回は割愛します。
さて、これで .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 より抜粋。
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 をいろいろと追いかけたのですが難解すぎて力尽きてそのまま放置状態です。解析はココまでしかすすんでません。
ってかこんなマイナーなエントリ役にたつんかいな？と思いつつも１人くらいには役に立つかも。ってか未来の自分？？と思いつつ書き残しました。
コメントやシェアをお願いします！
muraoka17
NetApp + Solaris 9 クライアントででました。
CVS 管理下のファイルを screen 上で vim で開いていたのに気付かずに、cvs up してしまったのが原因でした...。
消しても、消しても復活してなんだろうと思って、ググっていたところたどり着きました。
ありがとうございました。
sylphs
.nfsXXXXはSUNで経験しました。
rsyncの際にできてしまっているのですが、FTP PUTではできません。
rsyncはFILEの削除→作成をしているのが原因のようでした。
回避策として、umountをさせて失敗させています。
umountをする際に、tempファイルのCLEANUPをしてくれるので、その際に削除をしてくれます。
でも、実際にはそのmount volume上でプロセスが稼働しているため、umountに失敗する。と言った、大胆極まりない回避策を実施しています。
SUNなので、ソースを追えないため、ちょっと怖い回避策をしていますが、参考までにどうぞ。
drk
キヨリーノ さん＞まさかこの記事が他の方に役に立つとは思っても見ませんでした。記事にしておいて良かったと思いました。ｗ
キヨリーノ
NetApp使っていて.nfsXXXX みたいなファイルができたので
ググっていてこちらにたどりつきました。
大変参考になりました。
ありがとうございます。