DBQLとは
SQL単位の性能情報ログ
Oracleのv$sqlやDBA_HIST_SQLSTATに近いが、SQL単位でサマライズされず、1実行毎に性能情報を確認可能。
取得対象を事前に設定しておく必要がある。
コマンド
| 操作 | コマンド | 実行例・補足 |
|---|---|---|
| 全てのルールを確認 | SELECT * FROM DBC.DBQLRULESV; | |
| 「全て」に有効なルールを確認 | SHOW QUERY LOGGING ON ALL; | |
| データベースのルールを確認 | SHOW QUERY LOGGING ON [データベース名]; | |
| ロギングの開始 | BEGIN QUERY LOGGING ON [データベース名]; | |
| DBQL確認(メインログ) | select * from DBC.QryLogV; | |
| 特定のDBQL確認 | select * from DBC.QryLogV where QueryID = [クエリID]; |
実行例
ルールを確認
各ルールの意味はDBQLRulesV参照
show query logging on all;
*** Text of DDL statement returned.
*** Total elapsed time was 1 second.
---------------------------------------------------------------------------
Rule UserName "ALL" (From an ALL rule)
Rule UserId 00000000
Rule ZoneId 00000000
Account (Rule for any Account)
DBQL RULE:
Explain F
Object F
SQL F
Step F
XMLPlan F
StatsUsage F
UseCount F
Param F
FeatureUsage F
Verbose F
StatsDetails F
UtilityInfo F
NoColumns F
Summary F
Threshold F
ロギングの開始
全てのユーザに対するロギングを開始する場合
begin query logging on all;
begin query logging on all;
*** Begin querylog accepted.
*** Total elapsed time was 1 second.
select * from dbc.dbqlrulesv;
UserName
---------------------------------------------------------------------------
All
特定のDBQL確認
事前にfoldlineとsidetitlesを設定
.foldline;
.sidetitles;
select * from dbc.qrylogv where queryid = 307190827503924304;
*** Query completed. One row found. 128 columns returned.
*** Total elapsed time was 1 second.
*** Warning: Report has more than 100 column(s).
Only the first 100 column(s) will be displayed.
ProcID 30719
CollectTimeStamp 2020-09-02 10:52:09.040000
QueryID 307190827503924304
UserID 00000804
UserName SYSDBA
DefaultDatabase SYSDBA
AcctString DBC
ExpandAcctString DBC
SessionID 1,006
LogicalHostID 1
RequestNum 119
InternalRequestNum 119
TxnUniq ?
LockLevel ?
LogonDateTime 2020-08-22 12:11:56.360000
AcctStringTime ?
AcctStringHour ?
AcctStringDate ?
LogonSource (TCP/IP) c676 127.0.0.1 DBC 14592 ROOT BTEQ 01 LSS
AppID BTEQ
ClientID ROOT
ClientAddr 127.0.0.1
QueryBand =S> BLOCKCOMPRESSION=NO;
ProfileID ?
StartTime 2020-09-02 10:51:47.140000
FirstStepTime 2020-09-02 10:51:47.540000
FirstRespTime 2020-09-02 10:52:26.580000
ElapsedTime 0:00:39.440000
NumSteps 5
NumStepswPar 0
MaxStepsInPar 0
NumResultRows 4,194,309
NumResultOneMBRows 0
MaxOneMBRowSize 0
TotalIOCount 665
AMPCPUTime 16.568
ParserCPUTime 0.032
UtilityByteCount ?
UtilityRowCount ?
ErrorCode 0
ErrorText ?
WarningOnly
AbortFlag
CacheFlag
StatementType Select
StatementGroup Select
QueryText select * from t1;
NumOfActiveAMPs 2
MaxAMPCPUTime 16.568
MaxCPUAmpNumber 0
MinAmpCPUTime 0.000
MaxAmpIO 661
MaxIOAmpNumber 0
MinAmpIO 4
SpoolUsage 755,171,328
LSN ?
EstResultRows 4,194,309
EstProcTime 11.314
EstMaxStepTime 11,313.656
EstMaxRowCount 4,194,309
TDWMEstMemUsage 4.000
AMPCPUTimeNorm 665.039
ParserCPUTimeNorm 1.284
MaxAMPCPUTimeNorm 665.039
MaxCPUAmpNumberNorm 0
MinAmpCPUTimeNorm 0.000
ParserExpReq 0.117
ProxyUser ?
ProxyRole ?
SessionTemporalQualifier ?
CalendarName TERADATA
CPUDecayLevel 0
IODecayLevel 0
TacticalCPUException 0
TacticalIOException 0
SeqRespTime 39.040
ReqIOKB 794,584.000
ReqPhysIO 34.000
ReqPhysIOKB 2,372.000
DataCollectAlg 1
CallNestingLevel 0
NumRequestCtx 1
KeepFlag N
QueryRedriven N
ReDriveKind ?
LastRespTime ?
DisCPUTime 0.004
Statements 1
DisCPUTimeNorm 0.161
TxnMode BTET
RequestMode Exec
DBQLStatus ?
NumFragments ?
VHLogicalIO 0.000
VHPhysIO 0.000
VHLogicalIOKB 0.000
VHPhysIOKB 0.000
LockDelay ?
CheckpointNum 0
UnityTime 0.000
DBQL内容例（DBC.QryLogV）
420万件のレコードに対するフルスキャンを実行した場合の内容例
select * from t1;
| カラム | 値（例） | 内容 |
|---|---|---|
| ProcID | 30719 | SQLが実行されたPE(Processing Engine)のID |
| CollectTimeStamp | 2020-09-02 10:52:09 | クエリログが取得された時間 |
| QueryID | 307190827503924304 | クエリID |
| UserID | 0x00000804 | ユーザID |
| UserName | SYSDBA | ユーザ名 |
| DefaultDatabase | SYSDBA | デフォルトDB |
| AcctString | DBC | ユーザーがクエリーを発行した拡張アカウント文字列 |
| ExpandAcctString | DBC | ユーザーの拡張ログオン列 |
| SessionID | 1006 | セッションID |
| LogicalHostID | 1 | 論理ホストID |
| RequestNum | 119 | セッション内でクエリがリクエストされた番号 |
| InternalRequestNum | 119 | ストアドプロシージャが実行された際の内部リクエスト番号 |
| TxnUniq | ProcIdで使用されるトランザクション固有の部分 | |
| LockLevel | このリクエストに関連付けられた最高レベルのロック | |
| LogonDateTime | 2020-08-22 12:11:56 | ユーザがログオンした日時 |
| AcctStringTime | ユーザーが拡張アカウント文字列(ASE)を指定したときの&Tコードの結果 | |
| AcctStringHour | ユーザーが拡張アカウント文字列(ASE)を指定したときの&Hコードの結果 | |
| AcctStringDate | ユーザーが拡張アカウント文字列(ASE)を指定したときの&Dコードの結果 | |
| LogonSource | (TCP/IP) c676 127.0.0.1 DBC 14592 ROOT BTEQ 01 LSS | クエリを発行したログオンソース |
| AppID | BTEQ | クエリを発行したアプリケーションID |
| ClientID | ClientID | クエリを発行したクライアントID |
| ClientAddr | 127.0.0.1 | クエリを発行したクライアントアドレス |
| QueryBand | =S> BLOCKCOMPRESSION=NO; | クエリバンド値 |
| ProfileID | クエリを発行したプロファイルID | |
| StartTime | 2020-09-02 10:51:47 | クエリが発行された時間 |
| FirstStepTime | 2020-09-02 10:51:48 | クエリが実行（ディスパッチ）開始された時間 |
| FirstRespTime | 2020-09-02 10:52:27 | ホストに最初の返答があった時間 |
| ElapsedTime | 0:00:39 | 実行時間。実行開始から最初の返答があるまでの時間。実行完了までを指すOracleのElapsedTimeとは異なる。 |
| NumSteps | 5 | クエリーの(レベル1)ステップの合計数 |
| NumStepswPar | 0 | 並列ステップを持つ(レベル1)ステップの数 |
| MaxStepsInPar | 0 | クエリーに関して並列的に行なわれる(レベル2)ステップの最大数 |
| NumResultRows | 4194309 | クエリーで返された総行数 |
| NumResultOneMBRows | 0 | クエリーに返される一連の行内の1MB行(1MB > size > 64KB)の数 |
| MaxOneMBRowSize | 0 | クエリーで返される一連の行における最大1MB行の実際のバイト数 |
| TotalIOCount | 665 | クエリーで生成されたAMPのIOの数（論理） |
| AMPCPUTime | 16.568 | このクエリーで使用されるAMP CPU合計時間(秒)。全てのAMPのCPU時間合計。 |
| ParserCPUTime | 0.032 | クエリーに使用された構文解析プログラムとディスパッチャの合計CPU時間(秒) |
| UtilityByteCount | FastLoadジョブまたはMultiLoadジョブの一部としてクライアントで転送されたバイト数 | |
| UtilityRowCount | FastLoadまたはMultiLoadで読み込まれた行数 | |
| ErrorCode | 0 | エラー コード |
| ErrorText | エラーのテキスト | |
| WarningOnly | 警告モードでTDWM（Teradata Dynamic Workload Management）の実行中にエラーが報告された場合、またはまったくログに記録されていない場合は、警告コードTにtrueを返します。WarningOnlyがtrueでない場合は、フィールドにNULLがあります。 | |
| AbortFlag | アボートされた場合のフラグ | |
| CacheFlag | クエリーがリクエスト キャッシュ（※）にない場合は空白。（※）PEローカル メモリ内バッファであり、このバッファの中に、DML(データ操作言語)リクエストの構文解析時に生成されたステップが格納されます。 | |
| StatementType | Select | クエリーで実行された文のタイプ |
| StatementGroup | Select | DDL、DML、またはSELECT |
| QueryText | select * from t1; | クエリー テキスト。デフォルトは２００文字。 |
| NumOfActiveAMPs | 2 | このクエリーでアクティブなAMPの数 |
| MaxAMPCPUTime | 16.568 | クエリーでCPU使用率が最も高かったAMPのCPU時間(秒) |
| MaxCPUAmpNumber | 0 | CPU使用率が最も高かったAMP番号。 |
| MinAmpCPUTime | 0 | ステップでCPU使用率が最も低かったAMPのCPU時間(秒) |
| MaxAmpIO | 661 | ステップでI/O利用率が最も高かったAMP |
| MaxIOAmpNumber | 0 | ステップでI/O使用量が最も高かったAMP番号 |
| MinAmpIO | 4 | クエリーでI/Oが最も低かったI/Oカウント |
| SpoolUsage | 755171328 | クエリーでスプールに使用されたバイト数 |
| LSN | ロード ユーティリティの場合に使用 | |
| EstResultRows | 4194309 | このクエリーで返される行の推定数。→実際の結果行（NumResultRows）と同じ。 |
| EstProcTime | 11.31365571 | 最適化ルーチンからの推定処理秒数(0.001秒単位) |
| EstMaxStepTime | 11313.65571 | 最適化ルーチンからの最大ステップ推定時間(秒) |
| EstMaxRowCount | 4194309 | このクエリーのステップの最大推定行数 |
| TDWMEstMemUsage | 4 | 最大ステップの最大推定メモリ(MB)。 |
| AMPCPUTimeNorm | 665.039 | このクエリーで使用されたAMP CPU正規化合計時間(秒) ※正規化（Normalized）：異なるハード間での比較のため、CPUの性能に応じて一定の値（今回は40）を乗じたもの。 |
| ParserCPUTimeNorm | 1.284 | 正規化された構文解析プログラムCPU時間(秒) |
| MaxAMPCPUTimeNorm | 665.039 | AMPの正規化された最大CPU時間(秒) |
| MaxCPUAmpNumberNorm | 0 | CPU使用率が最も高かったAMP番号 |
| MinAmpCPUTimeNorm | 0 | AMPの正規化された最小CPU時間(秒) |
| ParserExpReq | 0.117037 | 計測した構文解析プログラムexpリクエストで経過した時間(1/100秒) ( |
| （中略） | ||
| SeqRespTime | 39.04 | すべてのステップが順に実行されたと仮定した場合の、応答時間の合計秒数 |
| ReqIOKB | 794584 | リクエストの論理IO使用量の合計キロバイト数 |
| ReqPhysIO | 34 | リクエストの物理I/O数 |
| ReqPhysIOKB | 2372 | リクエストの物理IO使用量の合計キロバイト数 |
| （中略） | ||
| MaxStepMemory | 0.187497139 | リクエストのいずれかのステップで使用される最大メモリ(MB) |
| （中略） | ||
| UsedIota | 33189000 | リクエストで使用されるIOトークンを返します。※IOTA=Input/Output Token Allocations |
結果整理
時間
CPU時間（AMPCPUTime）：16.568秒（AMP#0：16.568秒、AMP#1：0秒）
応答時間の合計（SeqRespTime）：39.04秒
I/O
論理IO（TotalIOCount）：665回（AMP#0：661回、AMP#1：4回）
リクエストの物理I/O数：34回
論理IO使用量（ReqIOKB）：800MB
物理IO使用量（ReqPhysIOKB）：2.3MB
以下の記載があるので、論理IO使用量（ReqIOKB）と物理IO使用量（ReqPhysIOKB）の比較ではキャッシュヒット率は出ない？
ResUsageデータは、論理I/Oの合計数と結果的に物理I/OになったI/Oリクエスト数を比較してキャッシュのヒット率を判断するのに役立ちます。DBQLデータは論理I/Oのみを追跡するため、DBQLデータとResUsageデータを一致させると混乱が生じる可能性がありますが、比較によってこのような混乱を回避できます。
[ResUsageとキャッシュのヒット率 • Teradata Vantage™ - データベースの管理 • リーダー • Teradataドキュメント]
(https://www.docs.teradata.com/reader/0rYfghiYcBZf2Y_ffU5UtA/g5iNObxkSysa2cbvQYGsEw)
メトリクス（PJIとUII）
PJI（Product Join Indicator ： 直積インジケータ）
算出式 ： (AMPCPUTime * 1000)/TotalIOCount
I/Oに対するCPU使用量。高い場合は直積などが発生している可能性がある。3以上で高いとされる。
（例）16.568秒 * 1000 / 665回 = 24.9
UII（Unnecessary I/O Indicator ： 不要IOインジケータ）
算出式 ： TotalIOCount / (AMPCPUTime * 1000)
CPU使用量に対するI/O。高い場合は少ない結果行を取得するためにフルスキャンが発生しており索引の付与が有効な可能性がある。
（例）665回 / （16.568秒 * 1000） = 0.04
容量
表容量：100MB（伸張後：450MB）
スプール利用量（SpoolUsage）：750MB
メモリ利用量(MaxStepMemory)：0.2MB
参考
[現在のルールの表示または終了 • Teradata Vantage™ - データベースの管理 • リーダー • Teradataドキュメント]
(https://docs.teradata.com/reader/0rYfghiYcBZf2Y_ffU5UtA/BGtZslufjN_j15ueWSARyw)
[ロギング文 • Teradata Vantage™ SQLデータ定義言語 構文規則および例 • リーダー • Teradataドキュメント]
(https://docs.teradata.com/reader/RknaJAFX_2CtUAZfB4_rTA/YENx89CDXxOhCQxNUgm65A)
[データベース ログについて • Teradata Vantage™ - データベースの管理 • リーダー • Teradataドキュメント]
(https://docs.teradata.com/reader/0rYfghiYcBZf2Y_ffU5UtA/SKXxl~CbpOZ_3HgIzG7usA)
[QryLogV • Teradata Vantage™ データ ディクショナリ • リーダー • Teradataドキュメント]
(https://docs.teradata.com/reader/fMqp0D_uNdzh8~BHZ2S~9w/OXXoK11F6pcW~NQshfKzWA)
DBQLRulesV • Teradata Vantage™ データ ディクショナリ • リーダー • Teradataドキュメント
Suspect Query Formulas • Teradata® Viewpoint User Guide • リーダー • Teradataドキュメント
UII and PJI? | Teradata Downloads