NSD Basics

2009年03月30日 00:02

Notes/Domino がクラッシュした際には、NSDファイルが生成されますが、このファイルの見方のようなものにはどの程度興味があるでしょうか。(R5.x以前をご利用の方は notes.rip と言うファイルになると思いますが)もちろんInternal Dataも多いので何から何まで紹介する事は出来ないのですが、概要だけでも知りたい、と思う方は多いのではないかな、と思ったので。

このブログでNSDの話を簡単に取り上げようかな、て思っているのですが、需要があるようだったら少し本格的な内容を考えてもいいかな、と思っています。拍手でもコメントでも何かフィードバック下さい。

Web上で入手できる資料では私が知っている限りでは、英語になってしまうのですがこれが一番いいのではないかな、と思います。 Lotusphere 2008の資料のようですね。


HND 107 - Using IBM Lotus Domino Notes System Disagnostic (NSD) Soft copy Hand out

NSDからどの程度の事がわかるのか?と言う事や簡単なデータの見方などが紹介されていてこのブログで取り上げたいなあ・・と思っているイメージにも近いのではないかと思います。

NSD 概要

2009年04月01日 00:04

NSD の記事ですが少し繰り上げて今日から書き始める事にします。

たくさんの記事があるのでブログの記事にするには小出しにしていくことになってしまいますが、何とか記事毎に話は完結させるようにするのでご了承下さい。

何から書き始めるか悩んだのですが始めから読み方のような話をしても分かりづらい気がしたので今日は概要について書いてみます。(尚、ここからの記事では 7.0以降のNSDを想定して書いています。それ以前のリリースでもほぼ同じ状況のはずですが、多少異なる点があることはあらかじめご了承下さい。)

NSDは、Notes System Diagnostics の略で、Lotus Notes/Domino の障害解析ツールです。
サーバークラッシュ・ハングではもっとも強力な調査ツールと言えるのではないかと思います。
NSDが使用されるもっとも典型的な問題は、クラッシュ・ハング・サーバースローダウン等の問題ですが、システム情報の収集やプロセスの状態などを確認したり、文字通りNotesの動くシステムの診断ツールと言えるのではないかと思います。

■ 透過的な実行
NSDは出来るだけ機能を透過的に利用できるようにするため、サーバー・クライアントでもほぼ同じように動き、多少プラットフォームごとに出力の差異はありますが、Macintosh を除くほぼ全てのプラットフォームで提供されています。

UNIXプラットフォームではNSDはnsd.sh とmemcheckと言うバイナリから構成され、Windows ではnsd.exeと言う実行ファイルから構成されていますが、出力などは可能な限り近い形式で表示されるようになっています。

■ NSD の構成
そもそもNSDはどのような情報が含まれているのでしょうか。
細かく見ていくと切りが無いのですが、大まかには以下のような情報から構成されます。

ヘッダー情報

バージョン情報
取得時間
ホスト名
使用したコマンドライン引数など

プロセス情報

Process Tree
プロセス一覧など

コールスタック

読み込んでいるDLL
各スレッド毎のコールスタック

Memcheck

ノーツ固有の情報
・ 共有メモリ、プロセスヒープなど
・ メモリハンドルの利用状況
・ 開いているデータベースやビューなど

環境情報

ネットワーク情報
ハードウェア情報(CPU数、搭載メモリなど)
環境変数
Notes.ini
パッチ情報など
※ プラットフォームによって出力には差異があります


NSDはこのように取得時のスナップショットを最大限に取得しますが、やはり不得手なエリア、と言うのはあるので、どんな問題でも行き詰ったらNSDで解決!とは行きません。

たとえばクライアントのUI操作に依存した部分はNSDだけではなかなか分からないですし、式言語やLotusScriptやJavaなどから発生しているエラーやランタイムエラーはやはり言語に応じた機能を使う方が効率的に問題特定が行えるので、TPOに応じた利用が必要な点は言うまでもないのですが、上のようにどのような出力が含まれるのか分かっていればこういう点は考えやすいのではないかなと思います。

次回から少しずつNSD の出力などについて詳細に入っていきたいと思います。

# NSDは長期に渡って取り上げようと思っているので、基本的には間に記事を挟みながらの少しずつの紹介になると思いますので、あらかじめ御了承下さい。。

Fatal Stack を見てみる

2009年04月06日 00:10

クラッシュやハングアップをした場合にサポートが最もよく見るのはコールスタック情報です。
残念ながらコールスタック上で表示される関数のインターフェースや仕様などについては公開されている情報はほとんどありませんが、既存情報との照合や動作の概要などを把握したり、有益な情報が得られる事も少なくありません。
 今日はNSDで最も特徴的とも言えるコールスタック情報とFatal Stackについての概要を説明しようと思います。

■ コールスタックとは
NSDでは、全ての Lotus Notes/Domino のプロセス、全てのスレッドでの関数の呼び出し履歴をコールスタック情報として出力します。
その他のセクションではプラットフォーム毎に多少の差異がありますが、どのNSD も何らかの形でコールスタック情報を持っています。
NSD取得時のコールスタックを確認する事によって、情報取得時の各関数の呼び出し順序などの情報を確認する事が出来ます。
NSDでは通常呼び出し順序は下から上になります。(System i だけは例外で上から下の呼び出し順序になります)
以下のようなコールスタックがあったときには、FunctionA()がFunctionB() を呼び出した事を示しています。

-> FunctionC()
-> FunctionB()
-> FunctionA()

つまり、上記のコールスタックは以下のような呼び出しが行われたことを示しています。
FunctionA() {
.....
FunctionB();
.....
}

FunctionB() {
.....
FunctionC();
.....
}

この辺は改めて書くまでも無いかもしれないですね。。。
NSDやNotesに限らず、Javaをはじめとする、C/C++ 等のクラッシュダンプ情報でも同様なので、よく知っている方も多いのではないかと思います。

■ Fatal Threadとは?
サーバーやクライアントがクラッシュした際に例外が発生したスレッドの事を、Fatal Threadと呼びます。 NSD内のFatal Thread を実際に見てみましょう。

WindowsのNSDでは以下の赤字のような「Fatal Thread」と言う文字が入るので比較的簡単に探す事が出来ます。

Fatal Thread の出力
############################################################
### thread 1/25: [ ntvdm: 0a74: 0cd8] FATAL THREAD
### FP=0013b260, PC=7c94eb94, SP=0013b1fc
### stkbase=00140000, total stksize=212992, used stksize=19972
############################################################
[ 1] 0x7c94eb94 ntdll.KiFastSystemCallRet+0 (b10,493e0,0,13b7e4)
[ 2] 0x7c802532 kernel32.WaitForSingleObject+18 (b10,493e0,3,13ba00)
@[ 3] 0x60193f25 nnotes.OSRunExternalScript@8+1269 (12c,1,1,0)
@[ 4] 0x601943ba nnotes.FRTerminateWindowsResources+986 (1,0,1010,1)
@[ 5] 0x6019477f nnotes.OSFaultCleanupExt@24+895 (1284bd0,1010,0,0)
@[ 6] 0x6019480a nnotes.OSFaultCleanup@12+26 (0,1010,0,10ec8d0f)
@[ 7] 0x601a0624 nnotes.OSNTUnhandledExceptionFilter@4+276 (13cd60,2b3,54200a0a,61657268)
@[ 8] 0x60178551 nnotes.Panic@4+481 (60b82d3b,10ec8d10,13cd8c,60008c62)
@[ 9] 0x601785cc nnotes.Halt@4+28 (2b3,10ec8d10,13cdc8,13cda4)
@[10] 0x60008c62 nnotes.HANDLEDereference@4+50 (10ec8d10,0,13db6c,0)
@[11] 0x60008b92 nnotes.InitDbContextExt@12+210 (10ec8d10,13cdc8,3,13cdfc)
@[12] 0x60008cd2 nnotes.InitDbContext@8+18 (10ec8d10,13cdc8,1864e63,e2)
@[13] 0x60015103 nnotes.NSFDbPathGet@12+19 (10ec8d10,13d31c,0,127)
@[14] 0x6002f2e1 nnotes.NSFCreateNotesURL@8+129 (13db3c,13dbd0,13dc90,11c9ee14)
@[15] 0x61d0cfdf nnotesws.DeskViewExporter::GetLinkNotesURL+543 (13dc90,f,c606fa0,13e7b8)
@[16] 0x6206a640 nnotesws.LinkExporter::ExportFormatData+112 (f,13dc8c,f,c606fa0)
@[17] 0x6180203a nnotesws.OLEDataTransfer::GetData+106 (c606fa0,13e7b8,13e7ec,9344914)
@[18] 0x618208d4 nnotesws.OLEDataImporter::ExportFormatData+180 (f,13e824,26c,9344918)
@[19] 0x61e03103 nnotesws.ViewDropTarget::Drop+67 (9344930,26c,2b1,1)
@[20] 0x61800d32 nnotesws.CNEMDropTarget2::OSDropTarget::Drop+114 (62140ed0,c606fa0,0,26c)


Windows 以外ではこのような表示が無いのですが、その場合には以下のようなキーワードを含むコールスタックに着目してください

Windows
Fatal, Panic, Halt, access violationなど

UNIX
“fatal”, “raise.raise”, “signal handler”, “abort”, or “terminate” など

多くの場合、Windows ではPanic()または Halt()、UNIX系ではfatal_error() がFatal Thread では呼ばれているはずなのですが、色々なケースがあるので柔軟に探してください。。


■ 関数名の表示
 実はこの表示はプラットフォーム毎に違うのですが、以下の例を見てみましょう。

@[10] 0x60008c62 nnotes.HANDLEDereference@4+50 (10ec8d10,0,13db6c,0)

これは、nnotes.dll のHANDLEDereference() と言う関数が呼ばれた、と言う意味です。
nlnotes.xxxxx であれば、当然nlnotes.exe の関数になるので必ずしも隠れている拡張子はdll とは限らないのですが、DLLかEXEだと思っていれば間違いないでしょう。

頭についている"@"は Windows NSD固有の機能なのですが、NotesのDLLから呼ばれた関数である事を示しています。nnotes.dllがNotesのプログラムディレクトリにあるので、そこから判断しています。
何気ない一行でも案外色々な意味があったりするのです。


技術情報の検索
上記のようにした、クラッシュでは、Fatal Threadにある関数名からナレッジベースを検索していきます。
 出来るだけ上の関数を取るのが普通ですが、上の例で言えばHalt()から上は通常のException Handlingなので検索には使用しません。なので、上のFatal Threadで太字にした部分などを検索に使用します。(ここではやり方だけを説明しているので、上の関数名による検索で適切な技術文書がヒットするかしないかはこの際重要ではありません。)
 
 技術文書がヒットしない事もよくあると思いますが、クラッシュが複数回発生した場合などは、このようにして発生したクラッシュを分類する事が出来るようになるはずです。

・ 同じタスク・同じコールスタックで発生
・ 異なるタスクだがほぼ同じコールスタックで発生している
・ 必ずしも同じとは言えないがよく似たコールスタックで発生している

自分の端末でクライアントが頻繁にクラッシュするときなどにちょっとIBM_TECHNICAL_SUPPORTディレクトリに出来たNSDを眺めてみてください。

以前にこのブログで紹介したLotus Notes Diagnostics UtilityなどではNSDを見て技術情報を簡易に検索してくれますが、このような方法を使っているはずです。

Current Procs - プロセス一覧を確認する

2009年04月13日 00:05

NSD の始めはCurrent Procsや OS Process Table のような名前でシステム上のプロセス一覧がツリー表示されるのが普通です。

以下がWindows NSDの抜粋です。
 プロセスの一覧(Windows)
04d8 01c8 0 11/27 12:36:00 [C:\WINNT\System32\llssrv.exe: 04d8]
* 0508 01c8 0 11/27 12:36:00 [d:\notes\nservice.exe =d:\notes\notes.ini: 0508]
-> 09d8 0508 0 11/27 12:36:25 [d:\notes\nSERVER.EXE =d:\notes\notes.ini: 09d8]
-> 0a08 09d8 0 11/27 12:36:25 [d:\notes\nlogasio.EXE NOTESLOGGER reserved : 0a08]
-> 0ba0 09d8 0 11/27 12:37:43 [d:\notes\nevent.EXE: 0ba0]
-> 0d5c 09d8 0 11/27 12:37:55 [d:\notes\nReplica.EXE : 0d5c]
-> 0d80 09d8 0 11/27 12:37:55 [d:\notes\nRouter.EXE : 0d80]
-> 0d88 09d8 0 11/27 12:37:55 [d:\notes\nUpdate.EXE : 0d88]
-> 0db8 09d8 0 11/27 12:37:55 [d:\notes\nAMgr.EXE : 0db8]
-> 1084 0db8 0 11/27 12:37:56 [d:\notes\namgr.EXE -e 1: 1084]
-> 0e1c 09d8 0 11/27 12:37:55 [d:\notes\nAdminP.EXE : 0e1c]
-> 0e54 09d8 0 11/27 12:37:55 [d:\notes\nCalconn.EXE : 0e54]
-> 0e94 09d8 0 11/27 12:37:55 [d:\notes\nSched.EXE : 0e94]
-> 0eb0 09d8 0 11/27 12:37:55 [d:\notes\nIWSTATG.EXE : 0eb0]
-> 0ee8 09d8 0 11/27 12:37:55 [d:\notes\nIWAGENT.EXE : 0ee8]
-> 10bc 0ee8 0 11/27 12:37:57 [iwcrdet.exe 3816: 10bc]
1138 10bc 0 11/27 12:37:57 [iwcrdmon.exe: 1138]
-> 0f08 09d8 0 11/27 12:37:55 [d:\notes\nIWINFO.EXE : 0f08]
-> 0f24 09d8 0 11/27 12:37:55 [d:\notes\nHTTP.EXE : 0f24]
-> 13d4 09d8 0 11/27 12:38:05 [d:\notes\nCldbdir.EXE: 13d4]
-> 13d8 09d8 0 11/27 12:39:05 [d:\notes\nClrepl.EXE: 13d8]
-> 0a68 09d8 0 11/27 12:40:05 [d:\notes\nClrepl.EXE: 0a68]
-> 0a14 09d8 0 11/27 12:40:15 [d:\notes\nClrepl.EXE: 0a14]
-> 0a84 09d8 0 11/27 12:40:15 [d:\notes\nClrepl.EXE: 0a84]
-> 0a8c 09d8 0 11/27 12:40:15 [d:\notes\nClrepl.EXE: 0a8c]
0c88 09d8 0 11/27 12:46:15 ["d:\notes\nsd.exe" -dumpandkill -termstatus 1: 0c88]

ここからPIDやプロセスの親子関係などが分かります。
Windowsの場合、Notesプロセスは、「->」と言うのが付いているのが分かります。
Notesのプログラムディレクトリから実行されているけれど、現在のディレクトリがデータディレクトリでない場合には、「*」で表示されます。

UNIX版のNSDでは ps コマンドのフォーマットなのでもう少しなじみがある形式かもしれません。
 プロセスの一覧(AIX)
Current Procs:
==============
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
200003 A root 1 0 0 60 20 1800c 744 Apr 23 - 4:12 /etc/init
240001 A root 3170 6994 0 60 20 1622b 164 Apr 23 - 0:00 /usr/sbin/biod 6
240401 A root 3446 1 0 60 20 22171 40 Apr 23 - 0:00 /usr/lib/methods/ssa_daemon -l ssa2
40103 A root 4034 1 0 60 -- 3843c 1968 15d49f4 Apr 23 - 0:00 /usr/lpp/ssp/css/fault_service_Worm_RTG_SP -r 13 -b 1 -s 4 -p 0 -a TB3 -t 36
(略)
340001 A notes1 25482 35730 13 64 22 2ca76 12640 * 07:50:06 - 42:17 /opt/lotus/notes/latest/ibmpow/server
340001 A notes2 32644 14746 1 64 22 207b0 3144 33fa08e8 07:52:21 - 2:27 /opt/lotus/notes/latest/ibmpow/pop3
340001 A notes2 33180 14746 0 64 22 35bb8 2380 * 07:52:21 - 4:48 /opt/lotus/notes/latest/ibmpow/replica
340001 A notes1 33660 25482 1 64 22 3639a 2192 33f3ce0c 07:51:30 - 7:59 /opt/lotus/notes/latest/ibmpow/event
(略)


このあとはNotes/Domino 関連のプロセスだけが表示されます。
 Notes プロセスの一覧(AIX)
------------------- PROCESS TREE ---------------------
Status is:
R -- process is running
D -- process is dead
T/status -- process terminated with exit status
S/signal -- process killed with signal
? -- Unknown status

username status pid program
root R 1 0 init

notes2 ? . 35730 1 ksh /domino/notesadmin/scripts/startup.instance
notes2 R .. 25482 35730 /opt/lotus/notes/latest/ibmpow/server
notes2 R ... 35880 25482 /opt/lotus/notes/latest/ibmpow/clrepl
notes2 R ... 28702 25482 /opt/lotus/notes/latest/ibmpow/cldbdir
notes2 R ... 18246 25482 /opt/lotus/notes/latest/ibmpow/replica
notes2 R ... 41976 25482 /opt/lotus/notes/latest/ibmpow/diiop
notes2 R ... 35524 25482 /opt/lotus/notes/latest/ibmpow/pop3
notes2 R ... 36336 25482 /opt/lotus/notes/latest/ibmpow/http
notes2 R ... 45076 25482 /opt/lotus/notes/latest/ibmpow/calconn
notes2 R ... 37880 25482 /opt/lotus/notes/latest/ibmpow/sched
notes2 R ... 26936 25482 /opt/lotus/notes/latest/ibmpow/adminp
notes2 R ... 42924 25482 /opt/lotus/notes/latest/ibmpow/amgr
notes2 R .... 44478 42924 /opt/lotus/notes/latest/ibmpow/amgr -e 1
notes2 R ... 46340 25482 /opt/lotus/notes/latest/ibmpow/update
notes2 R ... 45810 25482 /opt/lotus/notes/latest/ibmpow/router
notes2 R ... 33660 25482 /opt/lotus/notes/latest/ibmpow/event

Windowsでの出力は以下の通りです。
 Notes プロセスの一覧(Windows)
Ini File : d:\notes\notes.ini
Data Dir : d:\notedata
Prog Dir : d:\notes
Notes Build: Release 6.5.4FP3
Proc List:
d:\notes\nSERVER.EXE (9d8)
d:\notes\nlogasio.EXE (a08)
d:\notes\nevent.EXE (ba0)
d:\notes\nReplica.EXE (d5c)
d:\notes\nRouter.EXE (d80)
d:\notes\nUpdate.EXE (d88)
d:\notes\nAMgr.EXE (db8)
d:\notes\nAdminP.EXE (e1c)
d:\notes\nCalconn.EXE (e54)
d:\notes\nSched.EXE (e94)
d:\notes\nIWSTATG.EXE (eb0)
d:\notes\nIWAGENT.EXE (ee8)
d:\notes\nIWINFO.EXE (f08)
d:\notes\nHTTP.EXE (f24)
d:\notes\nAMgr.EXE (1084)
C:\Candle\IntelliWatch\MONITOR\iwcrdet.exe (10bc)
d:\notes\nCldbdir.EXE (13d4)
d:\notes\nClrepl.EXE (13d8)
d:\notes\nClrepl.EXE (a68)
d:\notes\nClrepl.EXE (a14)
d:\notes\nClrepl.EXE (a84)
d:\notes\nClrepl.EXE (a8c)



このプロセス一覧は特別に教えなくても見てれば分かるものですが、ここからは以下のような点を確認して、NSD取得時の状況を確認します。

・ 以前に起動したNotesプロセスが残ったりしていないか
・ プロセスの親子関係などは正しいか
・ 特定のプロセスが消えたりしていないか
・ Notes以外にどのようなプロセスが稼動しているシステムなのか


たぶんNSDの解説と言うとMemcheckのようなデータの見方を解説することを期待している方も多いと思うのですが、このようなOSのシステム診断情報がNSDにはたくさん含まれているので、是非活用してみてください。

NSD - Virtual Thread ID とPhysical Thread ID (TLS Mapping)

2009年04月20日 00:04

NSD で使用されるスレッド番号を見ていると、OS上で取得できるスレッドIDと一致しない事があって不思議におもうことがあるかもしれません。

これは色々な場面で誤解する元なのですが、NSDではほとんどの情報はOS上のスレッドIDでなく、仮想スレッドID(Virtual Thread ID または VirtualTID)で表記されている事を意識する必要があります。

なので、NSDではまず物理スレッドIDと仮想スレッドIDの関連付けを確認する必要があります。
その情報が確認できるのがTLS Mapping セクションです。以下のように表示されます。

------ TLS Mapping -----

NativeTID VirtualTID PrimalTID
[ nserver:02e8: 1184] [ nserver:02e8: 2] [ nserver:02e8: 2]
[ nserver:02e8: 2436] [ nserver:02e8: 4] [ nserver:02e8: 4]
[ nserver:02e8: 2280] [ nserver:02e8: 5] [ nserver:02e8: 5]
[ nserver:02e8: 2428] [ nserver:02e8: 6] [ nserver:02e8: 6]
[ nserver:02e8: 2176] [ nserver:02e8: 7] [ nserver:02e8: 7]
[ nserver:02e8: 2336] [ nserver:02e8: 8] [ nserver:02e8: 8]
[ nserver:02e8: 2332] [ nserver:02e8: 9] [ nserver:02e8: 9]
[ nserver:02e8: 2328] [ nserver:02e8: 10] [ nserver:02e8: 10]
[ nserver:02e8: 2324] [ nserver:02e8: 11] [ nserver:02e8: 11]
[ nserver:02e8: 2320] [ nserver:02e8: 12] [ nserver:02e8: 12]
[ nserver:02e8: 2316] [ nserver:02e8: 13] [ nserver:02e8: 13]
[ nserver:02e8: 2312] [ nserver:02e8: 14] [ nserver:02e8: 14]
(略)


実はR5当時のNSDではこのTLS Mappingに相当する情報がなかったため、この突合せは非常に難しい作業でした。

見方はほぼ自明だと思うのですが、ここからNative TIDとVirutal TID の関連付けを行います。
右端のPrimal Threadというのが気になる方が多いかと思いますが、これは通常仮想スレッドIDと同じ値になるのとNSDでは他のセクションで使用しないデータなのであまり気にする必要はありません。

これは、キーになっているNative TIDが一番最初に振られたVirtual ThreadIDの事なのですが通常ここは一致します。(理由は込み入っているので割愛させてください。。)

このセクションだけを見ると、大した意味がない情報に思えるかもしれないですが、NSDは仮想スレッドIDで様々な関連付けが行われている点とTLS MappingにNative<->Virtualの変換情報があることを知るだけでNSDを自分で見ることが出来る範囲が広がると思います。

この辺の話も少しずつ話していこうかと思います。

開いているデータベースを特定する

2009年04月24日 00:03

NSDでFatal Stackを探したあとはこのスレッドがどんなデータベースを開いているかが気になるかもしれません。

もちろん「Fatal Stackが開いている文書 = 問題の原因」とは限らないので、スタック情報と鑑みてこの手の話は判断しないといけないのですが、問題切り分けの参考になる事は多いのではないかと思います。

まず前回使った以下のFatal Threadを考えましょう。

Fatal Thread の出力
############################################################
### thread 1/25: [ ntvdm: 0a74: 0cd8] FATAL THREAD
### FP=0013b260, PC=7c94eb94, SP=0013b1fc
### stkbase=00140000, total stksize=212992, used stksize=19972
############################################################
[ 1] 0x7c94eb94 ntdll.KiFastSystemCallRet+0 (b10,493e0,0,13b7e4)
[ 2] 0x7c802532 kernel32.WaitForSingleObject+18 (b10,493e0,3,13ba00)
@[ 3] 0x60193f25 nnotes.OSRunExternalScript@8+1269 (12c,1,1,0)
@[ 4] 0x601943ba nnotes.FRTerminateWindowsResources+986 (1,0,1010,1)
@[ 5] 0x6019477f nnotes.OSFaultCleanupExt@24+895 (1284bd0,1010,0,0)
@[ 6] 0x6019480a nnotes.OSFaultCleanup@12+26 (0,1010,0,10ec8d0f)
@[ 7] 0x601a0624 nnotes.OSNTUnhandledExceptionFilter@4+276 (13cd60,2b3,54200a0a,61657268)
@[ 8] 0x60178551 nnotes.Panic@4+481 (60b82d3b,10ec8d10,13cd8c,60008c62)
(略)
NSDでは、「開いているデータベース」、「開いているビュー」、「開いている文書」などは別のセクションに表示されますが、ここではもっと簡単な情報として仮想スレッド毎にこれらの情報をまとめて出力している「VThreadセクション」から情報を拾う事を紹介します。

上で太字で示したプロセスID+Native ThreadID(またはPhysical Thread IDと呼ばれます)の情報をキーに探すと、以下のようなセクションが見つかります。
VThread セクション
** VThread [ ntvdm: 0a74: 0002]
.Mapped To: PThread [ ntvdm: 0a74: 0cd8]
.. SOBJ: addr=0x07dc3cf8, h=0xf0107056 t=0xca35 (BLK_TRACECONNECTION)
(略)
.. SessionID: fIOCP=N, [ 1: 1926] addr: ???: ???
(略)
.. Database: CN=Dxxxxxxx/OU=xx/OU=xx/O=xx!!mail\Dxx\Mxxxxx.nsf
.... DBH: 53, By: CN=Hirotaka Nagashima/OU=xx/O=xx, WasAccessed=No
...... doc: HDB= 53, NoteID= 0, hNote=0x29ad, flags=0000, class=0001
.... DBH: 56, By: CN=Hirotaka Nagashima/OU=xx/O=xx, WasAccessed=No
...... doc: HDB= 56, NoteID=2298, hNote=0x2a8d, flags=2200, class=0001
...... doc: HDB= 56, NoteID=18618, hNote=0x2ab5, flags=0200, class=0001
...... doc: HDB= 56, NoteID=589682, hNote=0x2b6f, flags=0200, class=0001
(略)
.... DBH: 242, By: CN=Hirotaka Nagashima/OU=xx/O=xx, WasAccessed=No
...... doc: HDB= 242, NoteID=222382, hNote=0x348a, flags=2000, class=0004
...... doc: HDB= 242, NoteID=220746, hNote=0x2bd0, flags=2000, class=0200
...... doc: HDB= 242, NoteID=220750, hNote=0x2bf0, flags=0000, class=0004 [Form Name="DelOptionInterim"]
...... doc: HDB= 242, NoteID=220758, hNote=0x2c0f, flags=0000, class=0004 [Form Name="(FollowUpMemoSubform)"]
(略)
.. file: fd: 680, C:\lotus\notes\data\~notes.lck
.. file: fd: 1180, C:\lotus\notes\data\user.dic
.. file: fd: 1540, C:\lotus\notes\panose.dat
(略)

太字にした部分がマッチするのが分かるでしょうか?
Vthread毎にここは表示されますが、ここを使用しているPhysical Threadの情報も表示されるのでここで使用する事が出来るのです。

ここの一覧に表示されたDatabase:やdoc:などの情報から開いているデータベースや文書・ビューの情報が分かるようになります。

前回のVThreadの話がちょっと面白くないと思った人もいるのかもしれないのですが、このセクションがNativeスレッドではなく仮想スレッド単位でレポートされているので、仮想スレッドの話も簡単にしておいた方がよいかな、と思って1クッション入れていました。

前回のVThreadの話がちょっと面白くないと思った人もいるのかもしれないのですが、このセクションがNativeスレッドではなく仮想スレッド単位でレポートされているので、仮想スレッドの話も簡単にしておいた方がよいかな、と思って1クッション入れていました。

分かりにくい点もあると思いますが、とりあえずは開いているビューやら文書やらの情報が探せるようになれば便利なのではないかな、と思います。

文書クラス

2009年04月30日 00:17

前回のNSDのトピックでは以下のようなVThreadセクションを確認する事を書きました。
VThread セクション
** VThread [ ntvdm: 0a74: 0002]
.Mapped To: PThread [ ntvdm: 0a74: 0cd8]
.. SOBJ: addr=0x07dc3cf8, h=0xf0107056 t=0xca35 (BLK_TRACECONNECTION)
(略)
.. SessionID: fIOCP=N, [ 1: 1926] addr: ???: ???
(略)
.. Database: CN=Dxxxxxxx/OU=xx/OU=xx/O=xx!!mail\Dxx\Mxxxxx.nsf
.... DBH: 53, By: CN=Hirotaka Nagashima/OU=xx/O=xx, WasAccessed=No
...... doc: HDB= 53, NoteID= 0, hNote=0x29ad, flags=0000, class=0001
.... DBH: 56, By: CN=Hirotaka Nagashima/OU=xx/O=xx, WasAccessed=No
...... doc: HDB= 56, NoteID=2298, hNote=0x2a8d, flags=2200, class=0001
...... doc: HDB= 56, NoteID=18618, hNote=0x2ab5, flags=0200, class=0001
...... doc: HDB= 56, NoteID=589682, hNote=0x2b6f, flags=0200, class=0001
(略)

今日はここで、些細な情報ですが、この部分に着目します。
...... doc: HDB= 56, NoteID=18618, hNote=0x2ab5, flags=0200, class=0001
この部分、実は以前にここで取り上げた文書クラスのトピックと関係があります。ここでもNSDと関連があることについて少し言及していますね。この部分は正に文書クラスを現しているので、以下のように数字から文書がどのような種類なのかを特定する事が出来ます。


0x0001 文書
0x0004 フォーム
0x0008 ビュー、フォルダ
0x0040 ACL
0x0200 エージェント
0x0800 複製式


Notes で文書を開いている、と言ってもフォームかビューか文書そのものか一概には言えないのでこのような情報が役に立つのです。見逃してしまいそうなくらいの情報ですがここで開いている文書の詳細情報を確認する事が出来る貴重な情報です。

NSD - 共有メモリの利用量を確認する

2009年05月20日 00:03

Lotus Notes/Domino のメモリ利用の特徴の一つとして共有メモリの使用量が高い事が挙げられると思うのですが、NSD解析でもDomino の共有メモリの使用量を確認するのは非常に重要です。
 この共有メモリの利用量確認はNSD解析でも非常に頻繁に確認される部分です。

NSDでは共有メモリの利用量は以下のようなセクションに出力されます。「Shared Memory:」とか「Shared Memory Stats」で検索すると出てきます。

共有メモリ使用量の出力の例 (1)
Shared Memory:
TYPE : Count SIZE ALLOC FREE FRAG OVERHEAD %used %free
S-DPOOL: 194 1450704896 1342667928 107553600 0 887590 92% 7%
Overall: 194 1450704896 1342667928 107553600 0 887590 92% 7%


共有メモリ使用量の出力の例 (2)
<@@ ------ Notes Memory Analyzer (memcheck) -> Shared Memory Stats (Time 12:47:42) ------ @@>

TYPE : Count SIZE ALLOC FREE FRAG OVERHEAD %used %free
Static-DPOOL: 434 1694498816 1643729036 49098576 0 2964704 97% 2%
Overall : 434 1694498816 1643729036 49098576 0 2964704 97% 2%


以下のように読みます。
いくつか説明をはしょっているところは通常は使用しなかったり、意味のある値が出力されていなかったりする部分なのでとりあえずは無視して構わないです。

Count: 使用されているメモリブロック数
Size: 確保されている共有メモリのサイズ
Alloc: 確保されている共有メモリのうち実際にDominoが内部的にアロケートしているもの
Free: 確保されている共有メモリのうち実際にDominoが内部的にアロケートしていないもの
%used: 使用率 (多少誤差はあると思いますが、Alloc/Size * 100 のような値になっているはずです)
%free: 未使用率 (Free/Size * 100 )

ここで挙げた例は二つとも共有メモリがいわゆる「使いすぎ」の状態のものです。
例(1) は1.35GBくらい、例(2)でも1.57GB くらい使用しています。通常は1GBを超えたくらいが要注意(ただこのくらいはよくあるので一概には言えません。)、1.2 GB ? 1.3GB を越えている場合、サポートでも利用量を下げる事によって現象の改善が見られないかを確認します。
 具体的にどのようにするか?と言うと、共有メモリの利用しているものでは、通常はバッファプールの寄与が一番大きい(750MB-1GB程度)ので、バッファプールを512MBくらいにして利用率が下がらないかを検討します。

 今更このブログで改めて説明するまでもない話ですが、32bitアプリケーションの場合、メモリアドレス(ポインター)は 0x00000000 - 0xFFFFFFFF の4GBの範囲で使用することが出来ます。
ただ、このアドレス範囲がすべて使用できることは無く、通常OSに依存してユーザーアプリケーションが使用できるメモリ空間やサイズは制限があります。

最近のOSはこの辺が設定により可変になっているものも多いですが目安としては以下のようになるのではないかと思います。

Windows: 2GB
Linux: 3GB
AIX:2048 MB (256MB * 8)

Solarisは確か3GBだったと思うのですがちょっと裏が取れる資料が手元に無かったので割愛しておきます。 Windows に詳しい方ですと、 この話を聞くと、Windows の/3GBスイッチの事が浮かんだ方もいると思いますが、3GBスイッチについては以下の文書を参照してください。要は7.0.1以降じゃないと有効になりません。

(参考)Lotus Domino の Windows /3GB スイッチのサポートについて (文書番号:730687)

ユーザー空間が3GBある場合には1GBを超えてもすぐに問題になることは無いのですが、やはり負荷の高い環境でも共有メモリは1GB超えて当たり前、と言う訳ではないのでこのような基準で見ています。

メモリ関連の問題が疑われる場合には頻繁に確認される部分なので、是非興味がある場合には一度目を通してみてください。

NSD - プロセスヒープの確認

2009年06月04日 00:19

前回のNSD関連のトピック では共有メモリの使用量の確認の話をしましたが、共有メモリの話が分かると、プロセスヒープの確認方法も案外簡単に分かるようになります。

各プロセス毎のプロセスヒープはNSDでは以下のように出力されます。

プロセスヒープメモリ使用量の出力の例 (1)
Process Heap Memory:
TYPE : Count SIZE ALLOC FREE FRAG OVERHEAD %used %free
S-DPOOL: 6 3145728 221436 2918148 0 9428 7% 92%
POOL : 1 17408 13538 972 0 2906 77% 5%
Overall: 6 3145728 220464 2919120 0 12334 7% 92%


新しいバージョンでは以下のようなフォーマットです。

プロセスヒープメモリ使用量の出力の例 (2)
<@@ ------ Notes Memory -> Usage Summary -> Process Heap Memory Stats :: [ nlnotes:  1318] (Time 14:47:30) ------ @@>

TYPE : Count SIZE ALLOC FREE FRAG OVERHEAD %used %free
Static-DPOOL: 54 28311552 26130380 2043076 0 211900 92% 7%
VPOOL : 117 2477436 649097 1452212 0 379807 26% 58%
POOL : 696 15042508 10526554 4107456 0 427970 69% 27%
Overall : 54 28311552 20570712 7602744 0 1019677 72% 26%


各列の意味も前回と同じです。

Count: 使用されているメモリブロック数
Size: 確保されている共有メモリのサイズ
Alloc: 確保されている共有メモリのうち実際にDominoが内部的にアロケートしているもの
Free: 確保されている共有メモリのうち実際にDominoが内部的にアロケートしていないもの
%used: 使用率 (多少誤差はあると思いますが、Alloc/Size * 100 のような値になっているはずです)
%free: 未使用率 (Free/Size * 100 )


よく混同されるのですが、プロセスヒープとスタック使用量を混同しないようにしてください。
プロセスヒープと言うのは「プロセス内のスレッド全てが利用できるメモリ領域」ですよね。
なのでここには各スレッドが消費しているスタックサイズは反映されませんし、共有メモリのサイズも反映されません。 「該当プロセスが消費しているメモリの大きさ」とは少しずれてしまいますよね。

さらに言うと、よくWindowsのタスクマネージャーで表示されるメモリ使用量と比較して疑問を持ってしまう人もいますが、これは共有メモリなども含んでしまうので、この値とは大きく異なる値になっているはずです。

ここはどのくらいの大きさだと大きいと判断するのか・・・・と言う事は難しいので一概には言えません。
たとえばAIXはOSの制限でプロセスヒープは512MBが上限なので、その辺を参考にしたりする事はありますが・・・ (AIXに詳しい方はこの数字もメモリモデルによって複数パターンがあるので反論があると思いますが。。。)



NSD: Top 10 Shared Memory Block Usage

2009年06月16日 00:18

以前は、NSDから共有メモリの利用量を確認する話をしました。

NSD - 共有メモリの利用量を確認する

ここで共有メモリの利用量が多い事が分かったときにNSDからもう少し分析を行うことが出来ます。
「Top 10 Shared Memory Block Usage」 と言う項目を探してください。


#------ Top 10 Shared Memory Block Usage:
BY SIZE | BY HANDLE COUNT
Type TotalSize Handles | Type Handles TotalSize
---------------------------- | ----------------------------
0x82cd 680972288 173 | 0x841c 572 2937390
0x82cc 12622080 173 | 0x841b 553 22430
0x834a 5767168 6 | 0xab04 377 14640
0x8252 4194304 4 | 0x8405 321 2172928
0x841c 2937390 572 | 0x8439 265 318344
0x8405 2172928 321 | 0x8604 255 6516
0x826c 1504338 23 | 0x8001 249 337146
0x824b 1497232 122 | 0x82cc 173 12622080
0x8a03 1355490 169 | 0x82cd 173 680972288
0x8433 1048576 1 | 0x8a03 169 1355490
-----------------------------------------------------------


最近のバージョンでは以下のように、「16bit Handles」と「Memhandles」に分けて表示されます。
これはメモリの仕様が変わったわけではなくNSDがより表示を詳細に表示するようになっただけです。
それぞれのハンドルの種類がどういう意味があるかについて気になる方もいると思いますが、ここで共有メモリを利用する場合にもNotes/Dominoでは2種類のハンドルがある、とだけ理解しておいてください。

詳細に理解するにはドミノのメモリブロックを全て理解する必要がありますが、残念ながらメモリブロックの詳細などについては公開されていないため、ここではメモリの利用方法をあらわす一意の識別子であるとご理解下さい。

<@@ ------ Notes Memory -> Usage Summary -> Top 10 Memory Block Usage :: (Shared) (Time 14:47:29) ------ @@>


<@@ ------ Notes Memory -> Usage Summary -> Top 10 Memory Block Usage -> 16 bit Handles By Size :: (Shared) (Time 14:47:29) ------ @@>

Type TotalSize Count Typename
-----------------------------------------------------------
0x880d 1569696 24 BLK_CL_OPENED_NOTE
0x0a0a 1371296 42 ???
0x824b 1063634 29 BLK_OPENED_NOTE
0x8150 457828 7 BLK_SEMWAITERPOOL
0x8a01 392424 6 BLK_NETPOOL
0x8405 312618 175 BLK_IDTABLE
0x8141 261616 4 BLK_STATICPOOL
0x9094 182428 342 BLK_NEM_BITMAP_COLORTABLE
0x8001 160806 114 ???
0x826c 130808 2 BLK_EXTMGR

<@@ ------ Notes Memory -> Usage Summary -> Top 10 Memory Block Usage -> Memhandles By Size :: (Shared) (Time 14:47:29) ------ @@>

Type TotalSize Count Typename
-----------------------------------------------------------
0x82cd 7872512 2 BLK_UBMBUFFER
0x8252 2097152 2 BLK_NSF_POOL
0x826d 1048576 1 BLK_NSF_DIRMANPOOL
0x8311 1048576 1 BLK_NIF_POOL
0x8a08 1048576 1 BLK_SESSION_POOL
0x8462 521612 221 BLK_CESCTX
0x938d 262168 1 BLK_SHARED_UNK_HASH
0x834a 262144 1 BLK_GB_CACHE
0x82cc 145920 2 BLK_UBMBCB
0x8a05 110000 1 BLK_NET_SESSION_TABLE



 フォーマットはバージョンによって色々ありますが、それぞれ列は以下のように理解します。

Type: メモリブロックの種類をあらわす16進の数値
TypeName: 上のタイプに付けられている名前
TotalSize: 実際にアロケートされているサイズ(バイト)
Count: 使用されている数

共有メモリではいくつか特徴的なことがあるのですが、まず上のTypeに当てられている数を見ると全て0x8xxxのように0x8から始まっています。
 これは0x8が共有メモリをあらわすためで、実際のBlock Typeは0x02cd となります。このへんは豆知識で、知っていても知らなくてもどうにかなる話ではあるのですが。。

次にDominoサーバーで取得したNSDでは多くの場合、BLK_UBMBUFFER が一番大きな値を示していると思いますが、これがいわゆるバッファープールのサイズとほぼ等しくなります。
 バッファープールの大きさと共有メモリの大きさがたまに混同されてしまう事がありますが、結局共有メモリの寄与で一番大きなものは、BLK_UBMBUFFER であることがこのことからも分かるのではないでしょうか。
 通常500MBを超えるようなブロックは注意しないといけないのですが、このブロックはバッファプールの設定に依存するので500MB-800MBの間を推移していればよいのではないかと思います。(バッファプール1GB 程度に達している場合はやや多目ですので設定を変えるように促すとは思いますが。)

ハンドル数に関してはいくつが多いとは一概に言えないのですが、通常はこのセクションは共有メモリの利用量が大きい、などの症状がすでに共有メモリの利用量のセクションから確認できているために、この辺の問題を疑ってから見ることが多いのでどのブロックの寄与がもっとも大きいかを確認していれば分かるのではないかと思います。 Databaseの処理が多いときは、BLK_VARRAYやBLK_VARRAY_CHUNKの数も多めに出るので、BLK_UBMBUFFER を含めたこの3つのブロックが多いときはまずは無視してみます。

この数が多いときはメモリーリークなどの問題も疑わないといけないので、ややこしいですし、ブロックとかハンドルの詳細が見えないのでやや分かりにくい点もあると思うのですが、このようにして「共有メモリの利用量が多い」と言う問題が分類していく事が可能である事はわかっていただけたのではないかと思います。


最新記事