What is Query Logging with Teradata DBQL Tables?
Query Logging is a feature that allows us to analyze workload and resource usage and to do performance tuning.
How Is Query Logging Implemented?
The Query Logging Framework consists of a set of DBC tables (called the Teradata DBQL tables) that store the performance indicators for a group of requests, each request, or request steps. Which key figures are stored and how detailed can be configured.
Does the information in the DBQL tables represent 100% of the workload of a Teradata system?
No, because as mentioned above we can define which information should be stored and in which detail. So-called filters are used to log only the required information. Detailed information can be aggregated and is then only available in aggregated form.
It should also be noted that for performance reasons, the collected information is not available in real-time in the DQBL tables, but is cached in memory and written at intervals (e.g. every 10 minutes). In the case of a system restart, all information that has not yet been written from the cache to the DBQL tables will be lost.
The DBSCOntrol option “DBQLFlushRate” controls in which intervals the cache is written to the DBQL tables.
If the cache is to be written immediately this can be done with this command:
FLUSH QUERY LOGGING WITH ALL;
How is it determined how much information about which objects should be collected?
Query logging is controlled by the following commands:
BEGIN QUERY LOGGING / END QUERY LOGGING
The precisely defined logging rules are stored in table DBC.DBQLRulesV.
How can I determine which rules are activated?
One way is by using this command:
SHOW QUERY LOGGING ON ALL;
Rule UserName “ALL” (From an ALL rule)
Rule UserId 00000000
Rule ZoneId FFFFFFFF
Account (Rule for any Account)
WITH NONE (No DBQL Logging)
Another possibility is to query the table with the rules:
SELECT * FROM DBC.DBQLRulesV;
Which users can enable or disable DBQL?
Only those who have EXECUTE permissions on the following macro:
GRANT EXECUTE ON DBC.DBQLAccessMacro TO DWHPRO;
Which DBQL tables should always be activated?
From experience, we recommend to always activate DBQL for all database objects. At least for the table DBQLOGTBL, DBQLOBJLOG and DBQLSQLTBL should be logged completely and without any filter:
BEGIN QUERY LOGGING WITH SQL, OBJECTS LIMIT SQLTEXT=0 ON ALL;
Teradata logs information for the above tables in a very efficient (caching) way and the impact on system performance is negligible.
Logging for users, accounts, and applications should be used on-demand. Below are two examples:
BEGIN QUERY LOGGING LIMIT THRESHOLD=100 CPUTIME AND SQLTEXT=5000 ALL ACCOUNT = ‘Account’;
BEGIN QUERY LOGGING LIMIT THRESHOLD=100 CPUTIME AND SQLTEXT=5000 ALL ON APPLNAME = ‘AppName’;
How should Query Logging for Tactical Queries be done?
For optimized tactical queries, summary logging in DBQL is typically sufficient and avoids the performance impact standard logging can have on a system with a massive amount of tactical queries. Stil, standard logging can be beneficial in the optimization phase to check if our tactical queries are cached as expected (column “CacheFlag” in table DBC.DBQLOGTBL).
For tactical queries, we are interested in recognizing whether the runtimes are stable and in the single-digit second range. Summary logging is ideal for analysis. Here is an example where we divide the runtimes into three groups:
BEGIN QUERY LOGGING LIMIT SUMMARY = 1,5,10 ON DWHPRO;
With the below query, we can then analyze our tactical workload:
t02.DATABASENAME AS DB,
t01.CollectTimeStamp AS TS,
t01.QueryCount AS CNT,
t01.QuerySeconds AS SEC,
t01.TotalIOCount AS IO,
t01.AMPCPUTime AS CPU,
t01.LowHist AS L,
t01.HighHist AS H
FROM DBC.DBQLSUMMARYTBL t01
t01.UserId = t02.DatabaseId
WHERE DATABASENAME = ‘DWHPRO’
ORDER BY T02.DATABASENAME,t01.CollectTimeStamp, t01.LowHist;
LowHist and HighHist define the range of seconds over which a session’s queries were summed up. There are only records for a specific range written if at least one query falls into it. QueryCount counts the number of queries per range; QuerySeconds is the summed up execution time of all queries in a range. Here is an example result set of the query shown above:
The Teradata DBQL Tables
Query logging includes a variety of table/view combinations in the DBC database:
- DBC.DBQLOGTBL and DBC.QryLogV
Saves one row per query with the aggregated key figures like the number of CPU seconds, number of IOs, and much more.
- DBC.DBQLStepTbl and DBC.QryLogStepsV
The individual steps of a query are saved here, including the important key figures for each query system.
- DBC.DBQLObjTbl and DBC.QryLogObjectsV
One row per database object used is stored here.
- DBC.DBQLSqlTbl and DBC.QryLogSQLV
All SQL text is stored here in the common record for table DBC.DBQLOGTBL. This may require several rows per query.
- DBC.DBQLSummaryTbl and DBC.QryLogSummaryV
Certain filters cause that the information about requests is not stored individually in DBC.DBQLOGBTBL, but only aggregated with other queries in this table.
- DBC.DBQLExplainTbl and DBC.QryLogExplainV
Saves the individual steps of the Execution Plan
- DBC.DBQLXMLTbl and DBC.QryLogXMLV
Saves the Execution Plan of the queries as XML
Stores workload management events
Stores workload management exceptions
Teradata DBQL Logging Levels
Query logging can be enabled for all users or for specific users:
BEGIN QUERY LOGGING ON ALL;
BEGIN QUERY LOGGING ON DWHPRO;
It can also be restricted to the account or a combination of account and user:
BEGIN QUERY LOGGING ON DWHPRO ACCOUNT = ‘TheAccount’;
Logging can also be restricted to certain Teradata applications:
BEGIN QUERY LOGGING ON APPLNAME = ‘Application’;
The WITH Option
Which details about an account, user of the application should be logged is determined by the “WITH” option:
BEGIN QUERY LOGGING ON DWHPRO WITH
Turn off query logging for the specific user, account or application
Log DBC.DBQLOGTBL plus EXPLAIN, OBJECTS, SQL, STEPINFO
Log DBC.DBQLOGTBL plus the EXPLAIN text
Log DBC.DBQLOGTBL plus the objects accessed
Log DBC.DBQLOGTBL plus the entire SQL text
Log DBC.DBQLOGTBL plus all steps of the query
Log DBC.DBQLOGTBL plus the Explain Plan as XML
Log DBC.DBQLOGTBL plus statistics usage
The LIMIT Option
The LIMIT option determines how much information is stored:
Determines the length of the SQL text which is stored. The default is 200 characters. It can be between 0 and 10,000 characters
It does not log into DBC.DBQLOGTBL and only writes counts of queries each 10 minutes
Rows are generated in DBC.DBQLOGTBL depending on certain thresholds (CPU seconds, etc.) defined. If the measure is below the threshold only a summary row is written into DBC.DBQLSummaryTbl
Difference Between SUMMARY And THRESHOLD
Both types of logging can use additional filters: Seconds, milliseconds, CPU milliseconds, normalized CPU milliseconds, or Number of IOs.
With SUMMARY these filters have the effect that the queries are arranged in a group. The information is only saved in table DBC.DBQLSummaryTbl.
SUMMARY = n1, n2, n3 [ELAPSEDSEC, ELAPSEDTIME, CPUTIME, CPUTIMENORM or IOCOUNT]
With THRESHOLD these filters have the effect that the queries are either written to the DBC.DBQLOGTBL or to DBC.DBQLSummaryTbl.
THRESHOLD = n [ELAPSEDSEC, ELAPSEDTIME, CPUTIME, CPUTIMENORM or IOCOUNT]
Query Logging Examples
BEGIN QUERY LOGGING ON ALL;
Logs default row for all users, accounts, and applications
BEGIN QUERY LOGGING ON ALL;
BEGIN QUERY LOGGING WITH NONE ON DWHPRO;
Logs default row for all users but exclude DWHPRO in a second step
BEGIN QUERY LOGGING WITH NONE ON APPLNAME = ‘FASTLOAD’;
Logs all request of all fastloads
BEGIN QUERY LOGGING WITH NONE LIMIT THRESHOLD = 500 CPUTIME ON ALL;
Logs default row for all queries above 100 CPU milliseconds otherwise counts the query in the DBC.DBQLSummaryTbl
BEGIN QUERY LOGGING LIMIT SUMMARY = 100, 1000, 2000 CPUTIME ON ALL;
Logs in DBC.DBQLSummaryTbl in 4 different groups
- The query takes up to 100 milliseconds
- The query takes up to 1000 milliseconds
- The query takes up to 2000 milliseconds
- The query takes more than 2000 milliseconds
BEGIN QUERY LOGGING LIMIT THRESHOLD = 100 IOCOUNT ON ALL;
Log a default row in DBC.DBLOGTBL if the query needs more than 100 IOs or count the query in DBC.DBQLSummaryTbl if the query needs up to 100 I/Os.
The Teradata DBQL Table Key Figures
These are the key figures we need most often for tuning queries with DBQL:
- Query Start Time and Query End Time
- Parsing Time of the Query
- Error Codes
- Total CPU Time (in centiseconds)
- Total IO Count
- Workload Delay Times
- The Query Text (truncated)
The above metrics are available in DBQLOGTBL; the logging into this table is enabled by default on every Teradata system and is often the only way to determine performance indicators.
The step log (DBQLStepTbl) can be used to gather additional and more detailed information for each query step:
- Query Step Timings (Start and End Time of each step)
- Row Counts per Step
- The activity of each Step (Join, Redistribution, etc.)
- CPU and IO usage for each step
This is the link to the official Teradata DQBL documentation, where you can find even more details:
Teradata Official Documentation for DQBL
What Are The Most Useful DBQL Performance Indicators?
The following Teradata Performance Indicators look at a query from different angles and give a good overview of whether a query can be improved due to problems. All columns are available in the table DBC.DBQLOGTBL.
The DBQL Product Join Indicator
As we can see from the name, unwanted product joins can be detected by this indicator.
Bad product joins can be recognized by the CPU to I/O ratio. High values are an indication that a product join is being executed. The number of comparisons results in a high number of I/Os. This is the formula to calculate the indicator:
CASE WHEN TotalIOCount = 0 THEN 0 ELSE (AMPCPUTime * 1000)/TotalIOCount END
If the value of the product join indicator is higher than 3 it is worth checking the execution plan for product joins.
However, a high value for the product join indicator can also have another reason such as:
- Aggregations of large amounts of data that pass through the memory. Since the aggregation takes place in memory, hardly any IOs are required, but many CPU seconds.
- Duplicate rows check when there are many hash collisions.
- Extensive string operations as they are often generated in the queries of BI tools.
- The use of Multivalue Compression (MVC) increases the product join indicator; since more rows fit into each data block when using MVC, fewer I/Os are needed to copy the data from disk to memory. This also applies to systems that do not have dedicated hardware for Block Level Compression (BLC). BLC needs a lot of CPU for decompressing the data
The DBQL Indicator For Wasted I/Os
This indicator is the opposite of the product join indicator in terms of calculation. It identifies steps that consume many I/Os but few CPU seconds. A high value for this indicator means that large amounts of data are copied. This is often a sign of the bad primary index choice or missing indexes.
Below is the formula for this indicator:
CASE WHEN AMPCPUTime = 0 THEN 0 ELSE TotalIOCount/(AMPCPUTime * 1000) END
As with the product join indicator, for values above 3, we should take a closer look at the execution plan.
The DBQL CPU and IO Skew Indicators
This is one of the most important indicators as it identifies the skewed workload. Skew is one of the main causes of poor performance on a Teradata system. With this indicator, we can search for skewed tables, joins, spools, etc.
The formula to calculate CPU skew is this one:
CASE WHEN (AMPCPUTime / (HASHAMP()+1) =0 THEN 0 ELSE MaxAmpCPUTime/(AMPCPUTime / (hashamp()+1) END
The formula to calculate I/O skew is this one:
CASE WHEN (TotalIOCount / (HASHAMP()+1) =0 THEN 0 ELSE MaxAmpIO/(TotalIOCount / (HASHAMP()+1) END
For indicator values above 2, we should check the execution plan for skew issues.
The DBQL CPU Impact Indicator
This indicator goes one step further and calculates the effect of skewing on the exploitation of the parallelism of the system.
The indicator is calculated like this:
MaxAmpCPUTime * (HASHAMP()+1)
The higher this value is the worse is the query.
DBQL Indicator Summary
The indicators shown above have the great advantage that they represent absolute values. As long as the execution plan does not change, a query will always deliver similar key figures.
DBQL Query Response Times
Finally, it should be mentioned that query runtimes are not a good indicator for performance tuning. The runtime behavior depends on too many variables and is not one of our primary optimization goals (although it is of course a secondary goal).