6.3.4 EDMRptTraceコマンドの出力例

EDMRptTraceコマンド実行結果の出力例を次に示します。

<この項の構成>
(1) サーバトレースの集計結果の出力例(-sv 指定)
(2) サーバトレースの集計結果のCSV形式での出力例(-sv -v 指定)
(3) クライアントトレースの集計結果の出力例(-cl 指定)
(4) クライアントトレースの集計結果のCSV形式での出力例(-cl -v 指定)
(5) エントリの抽出例(-sv -x 抽出エントリ定義ファイル 指定)
(6) トレースファイル分割の出力例(-cl -w 指定)
(7) トレースファイル分割のCSV形式での出力例(-sv -w -v 指定)
(8) SUBTOTAL,TOTALの出力例(-sv -t 指定)
(9) SUBTOTAL,TOTALのCSV形式での出力例(-sv -t -v 指定)
(10) トレース表の出力例(-sv -vt 指定)
(11) 集計間隔を指定した出力例(-sv -s '開始時刻' -e '終了時刻' -d 集計間隔 指定)
(12) 集計間隔を指定したCSV形式での出力例(-sv -s '開始時刻' -e '終了時刻' -d 集計間隔 -v 指定)

(1) サーバトレースの集計結果の出力例(-sv 指定)

サーバトレースを解析して,ユーザプログラムの処理内容の集計結果を出力した例を次に示します。

# EDMRptTrace -sv
# COUNT START = 2000/06/19 15:00:00.000
# COUNT END   = 2000/06/19 18:00:00.001
# LOG START   = 2000/06/19 15:00:00.000
# LOG END     = 2000/06/19 18:00:00.000

program name   pid      message                                         times
-------------- -------- ----------------------------------------------- --------
prog01         00005124​ CdbrSession::Commit()                                  2
                       CdbrSession::Begin()                                   3
                       CdbrSession::GetSearchResult()                         5
              -------- ----------------------------------------------- --------
              00005132​ CdbrSession::Commit()                                 21
                       CdbrSession::Begin()                                  32
                       CdbrEqlStatement::Execute()                           18
                       CdbrSession::GetSearchResult()                        18
-------------- -------- ----------------------------------------------- --------
prog02         00009588​ CdbrSession::Commit()                                  7
                       CdbrSession::Begin()                                   8
                       CdbrSession::GetSearchResult()                         4
-------------- -------- ----------------------------------------------- --------

(2) サーバトレースの集計結果のCSV形式での出力例(-sv -v 指定)

サーバトレースを解析して,ユーザプログラムの処理内容の集計結果をCSV形式で出力した例を次に示します。なお,CSV形式での出力では,分類項目の内容(この例ではユーザプログラムのプログラム名とユーザプログラムのプロセスID)は,集計結果の行数分,繰り返し出力されます。

"#","EDMRptTrace -sv -v"
"#","COUNT START","2000/06/19","15:00:00.000"
"#","COUNT END","2000/06/19","18:00:00.001"
"#","LOG START","2000/06/19","15:00:00.000"
"#","LOG END","2000/06/19","18:00:00.000"
"program name","pid","message","times"
"prog01","00005124​","CdbrSession::Commit()",2
"prog01","00005124​","CdbrSession::Begin()",3
"prog01","00005124​","CdbrSession::GetSearchResult()",5
"prog01","00005132​","CdbrSession::Commit()",21
"prog01","00005132​","CdbrSession::Begin()",32
"prog01","00005132​","CdbrEqlStatement::Execute()",18
"prog01","00005132​","CdbrSession::GetSearchResult()",18
"prog02","00009588​","CdbrSession::Commit()",7
"prog02","00009588​","CdbrSession::Begin()",8
"prog02","00009588​","CdbrSession::GetSearchResult()",4

(3) クライアントトレースの集計結果の出力例(-cl 指定)

クライアントトレースを解析して,ユーザプログラムの処理内容の集計結果を出力した例を次に示します。

# EDMRptTrace -cl
# COUNT START = 2000/06/19 15:00:00.000
# COUNT END   = 2000/06/19 18:00:00.001
# LOG START   = 2000/06/19 15:00:00.000
# LOG END     = 2000/06/19 18:00:00.000

pid      tid      message                                         times
-------- -------- ----------------------------------------------- --------
00002365​ 00005124​ CdbrSession::Commit()                                  2
                 CdbrSession::Begin()                                   3
                 CdbrSession::GetSearchResult()                         5
        -------- ----------------------------------------------- --------
        00005132​ CdbrSession::Commit()                                 21
                 CdbrSession::Begin()                                  32
                 CdbrEqlStatement::Execute()                           18
                 CdbrSession::GetSearchResult()                        18
-------- -------- ----------------------------------------------- --------
00007845​ 00009588​ CdbrSession::Commit()                                  7
                 CdbrSession::Begin()                                   8
                 CdbrSession::GetSearchResult()                         4
-------- -------- ----------------------------------------------- --------

(4) クライアントトレースの集計結果のCSV形式での出力例(-cl -v 指定)

クライアントトレースを解析して,ユーザプログラムの処理内容の集計結果をCSV形式で出力した例を次に示します。なお,CSV形式での出力では,分類項目の内容(この例ではユーザプログラムのプロセスIDとユーザプログラムのスレッドID)は,集計結果の行数分,繰り返し出力されます。

"#","EDMRptTrace -cl -v"
"#","COUNT START","2000/06/19","15:00:00.000"
"#","COUNT END","2000/06/19","18:00:00.001"
"#","LOG START","2000/06/19","15:00:00.000"
"#","LOG END","2000/06/19","18:00:00.000"
"pid","tid","message","times"
"00002365​","00005124​","CdbrSession::Commit()",2
"00002365​","00005124​","CdbrSession::Begin()",3
"00002365​","00005124​","CdbrSession::GetSearchResult()",5
"00002365​","00005132​","CdbrSession::Commit()",21
"00002365​","00005132​","CdbrSession::Begin()",32
"00002365​","00005132​","CdbrEqlStatement::Execute()",18
"00002365​","00005132​","CdbrSession::GetSearchResult()",18
"00007845​","00009588​","CdbrSession::Commit()",7
"00007845​","00009588​","CdbrSession::Begin()",8
"00007845​","00009588​","CdbrSession::GetSearchResult()",4

(5) エントリの抽出例(-sv -x 抽出エントリ定義ファイル 指定)

この例では,-xオプションで,次の抽出エントリ定義ファイルを指定したと仮定します。

[Extract Trace]
msg

また,この例では,コマンド引数で,次のサーバトレースを指定したと仮定します。

Input_trace.log:
0000 2000/07/05 14:27:04.727   DocumentBroker   00006A41 00000001​    enter abc_enter()
0001 2000/07/05 14:27:04.728   DocumentBroker   00006A41 00000001​    exit abc_exit()
0002 2000/07/05 14:27:04.730   DocumentBroker   00006A41 00000001​    arg argc 9
0003 2000/07/05 14:27:04.731   DocumentBroker   00006A41 00000001​    msg msg_SELECT
0004 2000/07/05 14:27:04.732   DocumentBroker   00006A41 00000001​    call abc_call()
0005 2000/07/05 14:27:04.733   DocumentBroker   00006A41 00000001​    return abc_return()

サーバトレースからmsgエントリを抽出して出力した例を次に示します。

# EDMRptTrace -sv -x extract.def Input_trace.log
# COUNT START = 2000/07/05 14:27:04.727
# COUNT END   = 2000/07/05 14:27:04.734
# LOG START   = 2000/07/05 14:27:04.727
# LOG END     = 2000/07/05 14:27:04.733

0003 2000/07/05 14:27:04.731    DocumentBroker   00006A41 00000001​    msg msg_SELECT

(6) トレースファイル分割の出力例(-cl -w 指定)

クライアントトレースを分割して出力した例を次に示します。

# EDMRptTrace -cl -w
# COUNT START = 2000/07/24 19:00:00.000
# COUNT END   = 2000/07/24 19:00:00.028
# LOG START   = 2000/07/24 19:00:00.000
# LOG END     = 2000/07/24 19:00:00.027

date                    tid      message
----------------------- -------- -----------------------------------------------
2000/07/24 19:00:00.000 00000001​ enter CdbrEqlStatement::CdbrEqlStatement()
2000/07/24 19:00:00.002 00000001​ enter CdbrEqlStatement::Initialize()
2000/07/24 19:00:00.004 00000001​ enter CdbrCoreImp::SetObjectID()
2000/07/24 19:00:00.006 00000001​ enter CdbrEqlStatement::Set()
2000/07/24 19:00:00.008 00000001​ enter CdbrEqlStatement::ChangeGetObjCount()
2000/07/24 19:00:00.010 00000001​ enter CdbrEqlStatement::Execute()
2000/07/24 19:00:00.012 00000001​ enter CdbrEqlStatement::GetResult()
2000/07/24 19:00:00.014 00000001​ enter dbrDelete(SDBR_QUERYRESULT*)()
2000/07/24 19:00:00.015 00000001​ enter CdbrEqlStatement::GetACLMode()
2000/07/24 19:00:00.017 00000001​ enter CdbrEqlStatement::DeleteResult()
2000/07/24 19:00:00.019 00000001​ enter CdbrEqlStatement::Terminate()
2000/07/24 19:00:00.021 00000001​ enter CdbrCoreImp::ResetObjectID()
2000/07/24 19:00:00.023 00000001​ enter CdbrEqlStatement::~CdbrEqlStatement()
2000/07/24 19:00:00.025 00000001​ enter CdbrCoreImp::ResetObjectID()
2000/07/24 19:00:00.027 00000001​ enter CdbrSession::Commit()

(7) トレースファイル分割のCSV形式での出力例(-sv -w -v 指定)

サーバトレースを分割してCSV形式で出力した例を次に示します。

"#","EDMRptTrace -sv -w -v"
"#","COUNT START","2000/06/05","12:27:48.506"
"#","COUNT END","2000/06/05","12:27:48.516"
"#","LOG START","2000/06/05","12:27:48.506"
"#","LOG END","2000/06/05","12:27:48.515"
"date","time","tid","message"
"2000/06/05","12:27:48.506","00000001​","enter","CedmRasMsg::cs_setMsgFormatter()","sis01","WETG2J0","12491","000052823906310000040​a0d(userdoc)","EDMS000021122​","()"
"2000/06/05","12:27:48.506","00000001​","enter","CedmRasMsg::cs_setMsgFormatter()","sis01","WETG2J0","12491","000052823906310000040​a0d(userdoc)","EDMS000021122​","()"
"2000/06/05","12:27:48.507","00000002​","enter","CedmCmdClassDescriptionForMulti::Initialize()"
"2000/06/05","12:27:48.507","00000002​","msg","SELECT P9FFOR71O0OFC9972P521A2HD56,P9FFOR71O00GC99727V7140CF56,P9FFOR71O0OFC9972VM01ESQF56,P9FFOR71O00GC9972E061CD0LM5 FROM T9FFOR71O0OFC9972O521IUPU96 WHERE PI29HEI0K08PBO872DLUUMRGB4='00000000​ABC42239'"
"2000/06/05","12:27:48.507","00000002​","enter","Edm_sys_open_directory()"
"2000/06/05","12:27:48.514","00000002​","enter","Edm_sys_open_directory()"
"2000/06/05","12:27:48.514","00000003​","enter","CdbrSession::Commit()","sis01","WETG2J0","12491","000052823906310000040​a0d(userdoc)","EDMS000021122​","()"
"2000/06/05","12:27:48.514","00000003​","enter","CdbrSession::Begin()","sis01","WETG2J0","12491","000052823906310000040​a0d(userdoc)","EDMS000021122​","()"
"2000/06/05","12:27:48.514","00000003​","enter","CdbrEqlStatement::Execute()","sis01","WETG2J0","12491","000052823906310000040​a0d(userdoc)","EDMS000021122​","()"
"2000/06/05","12:27:48.515","00000003​","enter","CdbrSession::GetSearchResult()","sis01","WETG2J0","12491","000052823906310000040​a0d(userdoc)","EDMS000021122​","()"

(8) SUBTOTAL,TOTALの出力例(-sv -t 指定)

SUBTOTALおよびTOTALを出力した例を次に示します。

# EDMRptTrace -sv -t
# COUNT START = 2000/06/19 15:00:00.000
# COUNT END   = 2000/06/19 18:00:00.001
# LOG START   = 2000/06/19 15:00:00.000
# LOG END     = 2000/06/19 18:00:00.000

program name  pid      message                                         times
------------- -------- ----------------------------------------------- --------
prog01        00005124​ CdbrSession::Commit()                                  2
                      CdbrSession::Begin()                                   3
                      CdbrSession::GetSearchResult()                         5
             -------- ----------------------------------------------- --------
             00005132​ CdbrSession::Commit()                                 21
                      CdbrSession::Begin()                                  32
                      CdbrEqlStatement::Execute()                           18
                      CdbrSession::GetSearchResult()                        18
------------- -------- ----------------------------------------------- --------
SUBTOTAL               CdbrSession::Commit()                                 23
                      CdbrSession::Begin()                                  35
                      CdbrEqlStatement::Execute()                           18
                      CdbrSession::GetSearchResult()                        23
------------- -------- ----------------------------------------------- --------
prog02        00009588​ CdbrSession::Commit()                                  7
                      CdbrSession::Begin()                                   8
                      CdbrSession::GetSearchResult()                         4
------------- -------- ----------------------------------------------- --------
SUBTOTAL               CdbrSession::Commit()                                  7
                      CdbrSession::Begin()                                   8
                      CdbrSession::GetSearchResult()                         4
------------- -------- ----------------------------------------------- --------
TOTAL                  CdbrSession::Commit()                                 30
                      CdbrSession::Begin()                                  43
                      CdbrEqlStatement::Execute()                           18
                      CdbrSession::GetSearchResult()                        27
------------- -------- ----------------------------------------------- --------

(9) SUBTOTAL,TOTALのCSV形式での出力例(-sv -t -v 指定)

SUBTOTALおよびTOTALをCSV形式で出力した例を次に示します。なお,CSV形式での出力では,分類項目の内容(この例ではユーザプログラムのプログラム名とユーザプログラムのプロセスID)と-tオプションのSUBTOTALおよびTOTALは,集計結果の行数分,繰り返し出力されます。

"#","EDMRptTrace -sv -t -v"
"#","COUNT START","2000/06/19","15:00:00.000"
"#","COUNT END","2000/06/19","18:00:00.001"
"#","LOG START","2000/06/19","15:00:00.000"
"#","LOG END","2000/06/19","18:00:00.000"
"program name","pid","message","times"
"prog01","00005124​","CdbrSession::Commit()",2
"prog01","00005124​","CdbrSession::Begin()",3
"prog01","00005124​","CdbrSession::GetSearchResult()",5
"prog01","00005132​","CdbrSession::Commit()",21
"prog01","00005132​","CdbrSession::Begin()",32
"prog01","00005132​","CdbrEqlStatement::Execute()",18
"prog01","00005132​","CdbrSession::GetSearchResult()",18
"SUBTOTAL","","CdbrSession::Commit()",23
"SUBTOTAL","","CdbrSession::Begin()",35
"SUBTOTAL","","CdbrEqlStatement::Execute()",18
"SUBTOTAL","","CdbrSession::GetSearchResult()",23
"prog02","00009588​","CdbrSession::Commit()",7
"prog02","00009588​","CdbrSession::Begin()",8
"prog02","00009588​","CdbrSession::GetSearchResult()",4
"SUBTOTAL","","CdbrSession::Commit()",7
"SUBTOTAL","","CdbrSession::Begin()",8
"SUBTOTAL","","CdbrSession::GetSearchResult()",4
"TOTAL","","CdbrSession::Commit()",30
"TOTAL","","CdbrSession::Begin()",43
"TOTAL","","CdbrEqlStatement::Execute()",18
"TOTAL","","CdbrSession::GetSearchResult()"27

(10) トレース表の出力例(-sv -vt 指定)

サーバトレースのトレース表を出力した例を次に示します。トレース表は,-vオプションを指定しなくても,CSV形式で出力されます。

"#","EDMRptTrace -sv -vt"
"#","COUNT START"," 2000/06/19"," 02:18:19.388"
"#","COUNT END"," 2000/06/19"," 02:19:16.421"
"#","LOG START"," 2000/06/19"," 02:18:19.388"
"#","LOG END"," 2000/06/19"," 02:19:16.420"
"date","time","process ID","thread ID","classification","host name","program name","process ID","session ID","program ID","message"
"2000/06/19","02:18:19.388","00004FDD","0000186​E","msg","","","","","","UPDATE "edmClass_VTCRelationship" SET "edmProp_VTMode"=2,"dmaProp_Head"=? WHERE "dmaProp_OIID"='0000000000000​F10'"
"2000/06/19","02:18:52.261","00004FDD","0000186​E","msg","","","","","","CdabSqlStringValue::DoSetParam, SetParam:0bc46760-366c-11d2-917c-0000e21303670000000000000​F08"
"2000/06/19","02:18:59.392","00005FDD","0000186​F","enter","maruko","dbrsetmode","11519","00004fdd397e5ef20009c3f7(ACUser1)","EDMS000020445​","CdbrDMA::ReleaseObject()"
"2000/06/19","02:19:08.015","00004FDD","0000186​E","enter","maruko","dbrsetmode","11519","00004fdd397e5ef20009c3f7(ACUser1)","EDMS000020445​","CdbrSession::Commit()"
"2000/06/19","02:19:16.420","00004FDD","0000186​E","msg","","","","","","[FPT02] Session_Commit                  ( ObjectName=00004fdd397e5ef20009c3f7 )"

(11) 集計間隔を指定した出力例(-sv -s '開始時刻' -e '終了時刻' -d 集計間隔 指定)

集計の開始時刻(2000/06/19 14:30:00.000)と終了時刻(2000/06/19 16:30:00.000)に加えて,集計間隔(20)を指定してユーザプログラムの処理内容を集計して出力した例を次に示します。

# EDMRptTrace -sv -s '2000/06/19 14:30:00.000' -e '2000/06/19 16:30:00.000' -d 20
# COUNT START = 2000/06/19 14:30:00.000
# COUNT END   = 2000/06/19 16:30:00.000
# LOG START   = 2000/06/19 15:00:00.000
# LOG END     = 2000/06/19 16:00:00.000
# INTERVAL    = 20 minutes

# COUNT START = 2000/06/19 14:30:00.000

# No entry found.

# COUNT START = 2000/06/19 14:50:00.000

program name  pid      message                                         times
------------- -------- ----------------------------------------------- --------
prog01        00005124​ CdbrSession::Commit()                                  1
                      CdbrSession::Begin()                                   2
                      CdbrSession::GetSearchResult()                         3
------------- -------- ----------------------------------------------- --------

# COUNT START = 2000/06/19 15:10:00.000

program name  pid      message                                         times
------------- -------- ----------------------------------------------- --------
prog01        00005124​ CdbrSession::Commit()                                  4
                      CdbrSession::Begin()                                   5
                      CdbrSession::GetSearchResult()                         6
------------- -------- ----------------------------------------------- --------

# COUNT START = 2000/06/19 15:30:00.000

program name  pid      message                                         times
------------- -------- ----------------------------------------------- --------
prog01        00005124​ CdbrSession::Commit()                                  7
                      CdbrSession::Begin()                                   8
                      CdbrSession::GetSearchResult()                         9
------------- -------- ----------------------------------------------- --------

# COUNT START = 2000/06/19 15:50:00.000

program name  pid      message                                         times
------------- -------- ----------------------------------------------- --------
prog01        00005124​ CdbrSession::Commit()                                 10
                      CdbrSession::Begin()                                  11
                      CdbrSession::GetSearchResult()                        12
------------- -------- ----------------------------------------------- --------

# COUNT START = 2000/06/19 16:10:00.000

# No entry found.

この例では,集計対象となるのは,2000/06/19 14:30:00.000から2000/06/19 16:29:59.999までのトレースログエントリです。2000/06/19 14:30:00.000から20分間隔で集計しています。

ログ終了時刻2000/06/19 16:00:00.000を超えて2000/06/19 16:10:00.000に集計したときには,該当するエントリがない,つまりユーザプログラムによる処理がなかったため「No entry found.」という結果が出力されています。

(12) 集計間隔を指定したCSV形式での出力例(-sv -s '開始時刻' -e '終了時刻' -d 集計間隔 -v 指定)

集計の開始時刻(2000/06/19 14:30:00.000)と終了時刻(2000/06/19 16:30:00.000)に加えて,集計間隔(20)を指定してユーザプログラムの処理内容を集計してCSV形式で出力した例を次に示します。なお,CSV形式での出力では,分類項目の内容(この例ではユーザプログラムのプログラム名とユーザプログラムのプロセスID)は,集計結果の行数分,繰り返し出力されます。

"#","EDMRptTrace -sv -s '2000/06/19 14:30:00.000' -e '2000/06/19 16:30:00.000' -d 20 -v"
"#","COUNT START","2000/06/19","14:30:00.000"
"#","COUNT END","2000/06/19","16:30:00.000"
"#","LOG START","2000/06/19","15:00:00.000"
"#","LOG END","2000/06/19","16:00:00.000"
"#","INTERVAL",20,"minutes"
"#","COUNT START","2000/06/19","14:30:00.000"
"#","No entry found."
"#","COUNT START","2000/06/19","14:50:00.000"
"program name","pid","message","times"
"prog01","00005124​","CdbrSession::Commit()",1
"CdbrSession::Begin()",2
"CdbrSession::GetSearchResult()",3
"#","COUNT START","2000/06/19","15:10:00.000"
"program name","pid","message","times"
"prog01","00005124​","CdbrSession::Commit()",4
"CdbrSession::Begin()",5
"CdbrSession::GetSearchResult()",6
"#","COUNT START","2000/06/19","15:30:00.000"
"program name","pid","message","times"
"prog01","00005124​","CdbrSession::Commit()",7
"CdbrSession::Begin()",8
"CdbrSession::GetSearchResult()",9
"#","COUNT START","2000/06/19","15:50:00.000"
"program name","pid","message","times"
"prog01","00005124​","CdbrSession::Commit()",10
"CdbrSession::Begin()",11
"CdbrSession::GetSearchResult()",12
"#","COUNT START","2000/06/19","16:10:00.000"
"#","No entry found."