fbpx

If you are looking to have in-depth knowledge on how your load utilities (or even DSA jobs) are running in your environment or investigating their performance, the DBQLogTbl is just the beginning.

The DBQLogTbl does provide metrics for these utilities, but not as accurate and as abundant as what Teradata DBQLUtilityTbl can offer.

What is the Teradata DBQL Utility Log?

The DBQLUtilityTbl will provide a plethora of detail, including timestamps of different phases of a utility job (acquisition and application for FastLoad/MultiLoad/MLoadX utility protocols, select and export steps for the export utility) and a DSA job (dictionary-data-build-postscript phase), logical and physical io usage, CPU time…

It is interesting to have this logging for when you want to analyze how your utility jobs perform (amount of data loaded, time spent in a delay state, time spent per phase, etc…); ultimately archive these logs and be able to have a history big enough to see patterns, tendencies and decide on potential enhancements.

To start things off, you will need a particular level of logging for the user running the utilities:

BEGIN QUERY LOGGING ON SYSPROD WITH UTILITYINFO;

This logging level is quite beefy in the sense that you cannot set a CPU threshold on this same particular user; you will be logging everything.

This is important to keep note of because:

  • Your DBQL reports on the activity for this particular user (or in general) can potentially skyrocket (especially query counts)
  • The amount of data you are storing will increase since more data is logged

The DBQLUtilityTbl is a 129 column table; the corresponding view is QryLogUtilityV.

How to use the Teradata DBQL Utility Log

Here is a sample SQL that can narrow the information down:

SELECT 

CAST (StartTime AS DATE) logdate
,USERNAME
,sessionid
,UtilityName

/*if you have querybands defined in your utility jobs, it is a good idea to extract this information*/
,GETQUERYBANDVALUE(queryband, 0, 'JobName') AS JobName
,GETQUERYBANDVALUE(queryband, 0, 'UtilityDataSize') AS UtilityDataSize    
,GETQUERYBANDVALUE(queryband, 0, 'ClientLoadSessions') AS RequestSession  /*utility jobs can define a min and max sessions in their script*/
 
, NumSesOrBuildProc AS "GrantedSession" /*if you're using tasm workload management, what is allocated is not what is requested in the tpt script, but what is defaulted in tasm (if no utilitydatasize is defined in the queryband)*/

,EXTRACT ( HOUR   FROM Phase0StartTime ) AS hh
,EXTRACT ( MINUTE FROM Phase0StartTime ) AS mm
,jobstarttime AT TIME ZONE 'Europe Central' AS StartTime
,jobendtime AT TIME ZONE 'Europe Central' AS EndTime

/*this total elapsed time includes the time it spent waiting for a utility slot (waiting in delay state)*/
,((EndTime - StartTime) HOUR(4) TO SECOND) AS TotElapsedTime

/*easier to work with this format when graphing the data into excel*/
,CAST ( ( EXTRACT ( HOUR FROM TotElapsedTime) * 3600 + EXTRACT ( MINUTE FROM TotElapsedTime) * 60 + EXTRACT ( SECOND FROM TotElapsedTime) ) AS  DEC (10,2)) AS TotElapsedTime_sec
,CAST ( ( EXTRACT ( HOUR FROM TotElapsedTime) * 3600 + EXTRACT ( MINUTE FROM TotElapsedTime) * 60 + EXTRACT ( SECOND FROM TotElapsedTime) ) / 60.00 AS  DEC (10,2)) AS TotElapsedTime_min

/*actual elapsed time*/
,CAST ( ( EXTRACT ( HOUR FROM TotElapsedTime) * 3600 + EXTRACT ( MINUTE FROM TotElapsedTime) * 60 + EXTRACT ( SECOND FROM TotElapsedTime) ) - DelayTime AS DEC (10,2)) AS ActElapsedTime_sec
,CAST ( ( EXTRACT ( HOUR FROM TotElapsedTime) * 3600 + EXTRACT ( MINUTE FROM TotElapsedTime) * 60 + EXTRACT ( SECOND FROM TotElapsedTime) ) - DelayTime  / 60.00 AS DEC (10,2)) AS ActElapsedTime_min
,CASE WHEN DelayTime IS NULL THEN 0 ELSE DelayTime END AS DelayTime

/*phase1*/
, CAST ( EXTRACT(HOUR FROM ((phase1endtime - phase1starttime) HOUR TO SECOND)) * 3600 +
EXTRACT(MINUTE FROM ((phase1endtime - phase1starttime) HOUR TO SECOND)) * 60 +
EXTRACT(SECOND FROM ((phase1endtime - phase1starttime) HOUR TO SECOND)) AS DEC (10,2)) AS Phase1ElapsedTime
,CAST ( Phase1RowCount AS INT ) 
,CAST ( Phase2RowCount AS INT ) 
,CAST ( RowsInserted AS INT )
,CAST ( (Phase1RowCount - RowsInserted)  AS INT ) AS RowsRejected

/*phase2*/
, CAST ( EXTRACT(HOUR FROM ((phase2endtime - phase2starttime) HOUR TO SECOND)) * 3600 +
EXTRACT(MINUTE FROM ((phase2endtime - phase2starttime) HOUR TO SECOND)) * 60 +
EXTRACT(SECOND FROM ((phase2endtime - phase2starttime) HOUR TO SECOND)) AS DEC (10,2)) AS Phase2ElapsedTime

/*phase3*/
, CAST ( EXTRACT(HOUR FROM ((phase3endtime - phase3starttime) HOUR TO SECOND)) * 3600 +
EXTRACT(MINUTE FROM ((phase3endtime - phase3starttime) HOUR TO SECOND)) * 60 +
EXTRACT(SECOND FROM ((phase3endtime - phase3starttime) HOUR TO SECOND)) AS DEC (10,2)) AS Phase3ElapsedTime

FROM  dbc.DBQLUtilityTbl;

Depending on your needs, add columns to the SQL.

For this next part, you may want to check out these articles by Roland regarding the Fastload and Multiload utilities:

Having a history of DBQLUtilityTbl data, the following graphs can be produced:

*Please note that this is simulated data, and it may or may not depict an accurate behavior of a system.*

Graph 1: the amount of data vs. the time it took to load from the host machine to Teradata (phase1) for a specific job EXP-J1.

Teradata DBQL Utility Log

We can see that the data loaded every 4 days is doubled, which can explain the longer load times.

However, in the last few days of the month (Oct 29th to Oct 31st), the amount of data stays below 2 million rows, similar to a normal day, but the load times are still very high (around 400 seconds -or- about 6 minutes).

To explain this behavior, you will first have to look at how busy the Teradata system was (it can be very busy). If nothing out of the ordinary, you will have to look at the host machine sending this data (it can be very busy CPU and/or io wise – which can explain slower transfer speeds). Another suspect can be a busier network.

Graph 2: actual runtime vs time spent in delay state

DBQLUtilityTbl

It is the same context as the previous graph (slow load times during month-end), but this time we are looking at how long a specific job is spent waiting for a load slot (delayed state).

We observe that every 4 days, this job encounters some delay. This is most likely is due to a higher concurrency of TPT jobs running in the system. Without going into the details, the time spent in the delay state ranges from few seconds (Oct 4) to almost 200 seconds (a bit over 3mins) on Oct 16, 20, 24, and 28.

Graph 3: number of daily, weekly and monthly jobs for a given time frame

TPT

It can be interesting to see how many jobs ran by schedule (monthly, weekly, or daily) and by utility (fastload, multiload).

To correlate this graph with the previous analysis, we notice that on those days (Oct 16, 20, 24, and 28) where high delays were observed for that particular job (EXP-J2), more utilities were running (precisely more daily jobs using the tpt load protocol).

These graphs show a macro view of the situation. You will need to drill down by hour (and even by the minute for more granularity).

I hope this article has brought you some useful information regarding this logging level and what you can get out of it.

Don’t hesitate to post your comments for any questions or clarifications!

Buy now at Amazon
{"email":"Email address invalid","url":"Website address invalid","required":"Required field missing"}

You might also like

>