Oracle

December 27, 2011

Poor design hurts!

Filed under: Uncategorized — srivenu @ 10:55 am

I was in given a task of analysing and triaging performance issues in a system which exhibits performance problems periodically. Every 3-4 months the system is scrubbed, cleaned and optimized. Performance starts degrading gradually from then as new code moves in quickly and regularly.
At the start of my analyis, the project lead calls me up and asks me what needs to be done to avoid the recurrence of the performance problem? I joked if he could stop new code movement. Ofcourse he could not. The business domain is very dynamic and it wouldn’t be feasible/practical to halt or slow down the code movement. We exist for the business and not the other way round! Coming to practical aspects, this particular project, like the many i saw, has an outdated and skinny dev & test environments and so no real testing is possible. The developers come from different vendors/backgrounds and their oracle skills are not great. (As TomKyte says in his first book, any project where the developer’s treat the database as a black box is doomed to failure). There is almost no code review. So I did not have any practical answer for his question.

A few minutes after i started looking at the systems i saw the following and felt really pity for the project lead!

select 	count(*) 
from 	X 
where 	X.SR_NO in (
	select	SR_NO 
	from	(
		select	to_char((to_number(:1) + rownum - 1)) SR_NO 
		from	dual
		connect	by level <= to_number(:2) - to_number(:3) + 1
		)
	) 
and 	X.A = :4 
and 	X.B = :5
and 	X.C = :6

This was one of the sql’s that i observed to bottleneck the system. There were several other SELECT’s and UPDATE’s on the table X which all seemed to have this clause in common

where 	X.SR_NO in (
	select	SR_NO 
	from	(
		select	to_char((to_number(:1) + rownum - 1)) SR_NO 
		from	dual
		connect	by level <= to_number(:2) - to_number(:3) + 1
		)
	) 

At first i did not understand why the developer did not use a BETWEEN clause

select 	count(*) 
from 	X 
where 	X.SR_NO between to_number(:1) and to_number(:2)
and 	X.A = :4 
and 	X.B = :5
and 	X.C = :6

I thought the developer tried to implement a newly learnt trick of serial number generation using DUAL. But then it struck me and i immediately checked the table definition of X.
Ofcourse! SR_NO is defined as VARCHAR2(30).
That’s the reason why he could not use BETWEEN.
Well, he could have used it but the index on SR_NO would not be used if it was written that way.

I asked him the reason for declaring SR_NO as VARCHAR2(30) instead of NUMBER. I was dumbfound when he replied that oracle NUMBER types are only storing 10 digits and anything greater than that are stored as exponential! I explained to him that Oracle NUMBER type infact stores a precision of upto 39 digits and if he wanted to see more digits in SQL*PLUS, he just has to set a higher NUMWIDTH.

So he has chosen the wrong data type for a critical column and wrote convulted sql based on that.
Well in support of the developer, he is a java developer, who has been working on this project for the past 2 years in a stressful situation trying to fix a pile of problems which never seem to reduce.

December 25, 2011

Be very when careful tinkering with the STATISTICS_LEVEL setting

Filed under: Uncategorized — srivenu @ 11:24 am

Sometime back i was looking into the bad performance of some sql’s after the upgrade of a database from 10.2.0.4 to 10.2.0.5. Some of the sql’s started performing poorly since upgrade.

I started with one sql and I was in for a surprise when i checked the bind values peeked for that sql.

col sql_id head "SQL ID" form a13
col child_number head "Chi|ld|No" form 9999
col name head "Bind|Name" form a10
col POSITION head "Bind|Posi|tion" form 9999
col DATATYPE head "Data|type|ID" form 9999
col DATATYPE_STRING head 	"Datatype" form a14
col PRECISION head "Precision" form 9999
col scale head "Scale" form 9999
col MAX_LENGTH head "Max Bind|Length" form 9999
col WAS_CAPTURED head "Bind|value|Capt|ured|?" form a5
col lc head "Last|Captured" form a18
col VALUE_STRING head "Value|of Bind" form a15

select 	SQL_ID,
	CHILD_NUMBER,
	NAME, POSITION,
	DATATYPE, DATATYPE_STRING,
	PRECISION, SCALE, MAX_LENGTH, 
	WAS_CAPTURED, to_char(LAST_CAPTURED,'dd-mon-yy hh24:mi:ss') lc, 
	VALUE_STRING
from 	V$SQL_BIND_CAPTURE
where  	sql_id='f0yqgyfc7cz2v'
order	by 1,2,4
/


                                                                                   Bind
                                                                                   value
                Chi             Bind  Data                                         Capt
                 ld Bind        Posi  type                                Max Bind ured  Last               Value
SQL ID           No Name        tion    ID Datatype       Precision Scale   Length ?     Captured           of Bind
------------- ----- ---------- ----- ----- -------------- --------- ----- -------- ----- ------------------ ---------------
f0yqgyfc7cz2v     0 :B1            2     2 NUMBER                               22 NO
f0yqgyfc7cz2v     0 :B1            4     2 NUMBER                               22 NO
f0yqgyfc7cz2v     0 :B1            3     2 NUMBER                               22 NO
f0yqgyfc7cz2v     0 :B2            1     1 VARCHAR2(32)                         32 NO


No bind values!
Quick check and i found it to be the same same case with the other sql’s as well.

I then did a quick check for the whole system.

select  SQL_ID,
        CHILD_NUMBER,
        NAME, POSITION,
        DATATYPE, DATATYPE_STRING,
        PRECISION, SCALE, MAX_LENGTH,
        WAS_CAPTURED, to_char(LAST_CAPTURED,'dd-mon-yy hh24:mi:ss') lc,
        VALUE_STRING
from    V$SQL_BIND_CAPTURE
where   WAS_CAPTURED != 'NO'
order   by 1, 2, 4
/

no rows selected

I did a quick check for all parameter values containing the word bind.

col ksppinm head "Parameter" form a33
col ksppdesc head "Parameter Description" form a48
col ksppstvl head "Value" form a15
col ksppstdf head "Is|Defa|ult?" form a4 trunc
col alsession head "Alt|Sess|ion?" form a4 trunc
col alsystem head "Alter|Sys|tem?" form a4 trunc
col ismod head "Is|Modi|fied|?" form a4 trunc
col isadj head "Is|Adju|sted|?" form a4 trunc
col ksppstvf form 999

select 	ksppinm,ksppstvl,ksppstdf,  
	decode(bitand(ksppiflg/256,1),1,'TRUE','FALSE') alsession,  
	decode(bitand(ksppiflg/65536,3),1,'IMMEDIATE',2,'DEFERRED',3,'IMMEDIATE','FALSE') alsystem,
	decode(bitand(ksppstvf,7),1,'MODIFIED',4,'SYSTEM_MOD','FALSE') ismod, 
	decode(bitand(ksppstvf,2),2,'TRUE','FALSE') isadj,  
	ksppdesc 
from 	x$ksppi x, x$ksppcv y
where 	x.indx = y.indx
and	upper(x.ksppinm) like '%BIND%'
order 	by 1
/



                                                                 Is   Is
                                                  Is   Alt  Alte Modi Adju
                                                  Defa Sess Sys  fied sted
Parameter                         Value           ult? ion? tem? ?    ?    Parameter Description
--------------------------------- --------------- ---- ---- ---- ---- ---- ------------------------------------------------
_cursor_bind_capture_area_size    0               TRUE FALS IMME FALS FALS maximum size of the cursor bind capture area
_cursor_bind_capture_interval     900             TRUE FALS IMME FALS FALS interval (in seconds) between two bind capture f
                                                                           or a cursor

_cursor_cache_frame_bind_memory   FALSE           TRUE FALS FALS FALS FALS frame & bind buffer caching
_like_with_bind_as_equality       FALSE           TRUE TRUE IMME FALS FALS treat LIKE predicate with bind as an equality pr
                                                                           edicate

_optim_peek_user_binds            TRUE            TRUE TRUE IMME FALS FALS enable peeking of user binds
_optimizer_rownum_bind_default    10              TRUE TRUE IMME FALS FALS Default value to use for rownum bind
_px_bind_peek_sharing             TRUE            TRUE TRUE IMME FALS FALS enables sharing of px cursors that were built us
                                                                           ing bind peeking

_xpl_peeked_binds_log_size        8192            TRUE FALS IMME FALS FALS maximum bytes for logging peeked bind values for
                                                                            V$SQL_PLAN (0 = OFF)

_xsolapi_sql_use_bind_variables   TRUE            TRUE TRUE DEFE FALS FALS OLAP API enable bind variables optimization

9 rows selected.

The setting of “_cursor_bind_capture_area_size” to 0 did not look right.
The value for 400 for the other 10.2.0.4 databases.

I thought (but it did not seem right to me) that “_cursor_bind_capture_area_size” defaulted to 0 in 10.2.0.5
But on another 10.2.0.5, it was the default value of 400.

I then set it to 400

alter system set “_cursor_bind_capture_area_size” = 400
/

But the binds were still not getting captured. So i decided to

alter system flush shared_pool
/

And immediately i observed BIND value’s being captured again

select  SQL_ID,
        CHILD_NUMBER,
        NAME, POSITION,
        DATATYPE, DATATYPE_STRING,
        PRECISION, SCALE, MAX_LENGTH,
        WAS_CAPTURED, to_char(LAST_CAPTURED,'dd-mon-yy hh24:mi:ss') lc,
        VALUE_STRING
from    V$SQL_BIND_CAPTURE
where   WAS_CAPTURED != 'NO'
order   by 1, 2, 4
/


921 rows selected.

A quick search on the web revealed this good note by Yong Huang.
Yes it would be good to have a hierarchical view of all parameters based on their dependencies.
I wonder if there are any cyclical dependencies.

It seems that on this system the STATISTICS_LEVEL parameter was set to BASIC after the upgrade to 10.2.0.5 on Oracle’s suggestion for some other bug tracing purpose.

Moral of the story is to be very cautious when modifying the STATISTICS_LEVEL parameter as this could have a recursive impact on several other dependent parameters

Optimizer might ignore a more suitable superset composite index

Filed under: Uncategorized — srivenu @ 9:56 am

I thought i would post this note after modifying a composite index that was being overruled by the CBO on cost grounds.
The environment is Oracle 64-Bit 10.2.0.4 on Solaris 64-bit.

The sql in question is something like this


select 	.....
from 	X
where 	FILE_ID =:1 
and     STATUS = :2

There are 2 indexes on the table which could be used for this query

- INDEX_FILE_ID 		on X(FILE_ID) 
- INDEX_FILE_ID_STATUS_ISD	on X(FILE_ID, STATUS, ISD)

The table stats are like this


  Avg
 Free    Avg                                          
Space    Row                              
 In A    Len       No Of             Empty
Block    gth        Rows     Blocks Blocks
----- ------ ----------- ---------- ------
    0    172    16858045     589525      0

The column stats are like this


                                                                              Ave
                          NU                                                  Col
                          LL          Num                           Den  Num  umn
                          AB         Dist          Num               si Buck  Len
Column Name               LE         inct        Nulls               ty  ets  gth
------------------------- -- ------------ ------------ ---------------- ---- ----
FILE_ID                   Y       422,169            0   .0000023687196    1    6
STATUS                    N             3            0   .3333333333333    1    2
ISD                       N     4,525,479            0   .0000002209711    1   11

Here are the plans


select 	.....
from 	X
where 	FILE_ID =:1 
and     STATUS = :2

----------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name                 | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                      |    13 |  2236 |     7   (0)| 00:00:01 |
|*  1 |  TABLE ACCESS BY INDEX ROWID|             X        |    13 |  2236 |     7   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | INDEX_FILE_ID        |    41 |       |     4   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------


Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter("X"."STATUS"=:2)
   2 - access("X"."FILE_ID"=TO_NUMBER(:1))



select 	/*+INDEX(X INDEX_FILE_ID_STATUS_ISD)*/
	.....
from 	X
where 	FILE_ID =:1 
and     STATUS = :2


--------------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name                     | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                          |    13 |  2236 |    17   (0)| 00:00:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID|                       X  |    13 |  2236 |    17   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | INDEX_FILE_ID_STATUS_ISD |    13 |       |     4   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("X"."FILE_ID"=TO_NUMBER(:1) AND "X"."STATUS"=:2)


The range scan costs the same in both the plans.
The Table Access cost is very low for the first plan even though the it has to look up 41 rows compared to 13 in the second plan.
Its easy to figure out that the cost difference has something to do with Clustering Factor.

Following are the index stats

 

                                                                                              Avg     Avg
                                                                                         %   Leaf    Data
                                                 B               Cluste               Dist Blocks  Blocks
                                                Lev     Leaf      -ring     Number    inct    Per     Per
Index Name                Index Type Status     -el   Blocks     factor    Of Rows    keys    Key     Key
------------------------- ---------- ---------- --- -------- ---------- ---------- ------- ------ -------
INDEX_FILE_ID             NORMAL     VALID        3   154199    1237333   22618792    1.78      1       3
INDEX_FILE_ID_STATUS_ISD  NORMAL     VALID        3   249404   20071519   22772761   98.78      1       1

Lets start with the plan which shows index range scan on INDEX_FILE_ID_STATUS_ISD.
The CBO estimates that the after applying the predicate on FILE_ID & STATUS, 13 rows would be retrieved.
Due to the high clustering factor of INDEX_FILE_ID_STATUS_ISD the 13 rows would be located on 13 different table blocks and hence a cost of 13.

Now for the plan which shows index range scan on INDEX_FILE_ID.
The CBO estimated that after applying the predicate on FILE_ID, 41 rows would be retrieved.
Due to the low clustering factor on the INDEX_FILE_ID index, it needs to access only 3 distinct table blocks and hence a cost of 3.

We could easily find out the oddity of this logic.
Thinking logically, if we use the INDEX_FILE_ID index, we have to access all the table blocks (if not more) accessed by INDEX_FILE_ID_STATUS_ISD index.
So the clustering factor should be ignored in cost comparision of these 2 indexes.
We could understand if the composite index is rejected based on higher range scan cost.

The CBO is just a piece of code and can be forgiven for figuring out this logic.
Also its not quite common to see a column repeatedly indexed.
But if such scenarios are common, i can think of an additional logic to be added to the CBO wherein,
if there are composite column predicates with superset/subset possibilities on the same set of columns,
the CBO should ignore clustering factor in determining the index path and will always use the superset index based only on the index access cost.

Hope this note also serves as a caution to DBA’s from cramming more than “needed” columns in an index.
The high clustering factor of INDEX_FILE_ID_STATUS_ISD was actually caused by ISD column.
Dropping ISD column from the index resolved the issue.

December 20, 2011

Performance Tuning Informatica PowerCenter

Filed under: Uncategorized — srivenu @ 10:58 am

This post relates to some recent task assigned to me in a DWH environment. The environment constituted Oracle 10.2.0.4.0 64-bit on Sun Solaris 5.10. The ETL tool is Informatica power center 8.6.1. The problem was that the daily ETL job cycle was taking more than 24 hours to complete.
I had previously worked in a large Data Warehousing environment, but that place was using custom ETL tools. Informatica was pretty new to me and I had to study for sometime to understand the architecture of Informatica Power Center. It wasn’t easy getting Informatica docs (I wonder why software vendors dont make their software and documentation available free and easy for education purpose like Oracle !). I found a good note on “Performance Tuning” Informatica PowerCenter by Jishnu Pramanik.
As usual I wanted to start working on critical jobs. So I had asked for and was given a list of 10 badly performing critical chains.
I started by looking at the informatica session logs for these critical chains. Following is the session log of one such chain.

**************

Severity Timestamp Node Thread Message Code Message
INFO 11/1/2011 12:26:19 PM node02_dwprod MANAGER PETL_24031
***** RUN INFO FOR TGT LOAD ORDER GROUP [1], CONCURRENT SET [1] *****
Thread [READER_1_1_1] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8007.899649] secs
Total Idle Time = [7662.680904] secs
Busy Percentage = [4.310977]
Thread [TRANSF_1_1_1] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8007.438513] secs
Total Idle Time = [128.307174] secs
Busy Percentage = [98.397650]
Thread work time breakdown:
EXPTRANS3: 0.103520 percent
C_DISCOUNT_SCENARIOS_1: 0.025880 percent
C_DISCOUNT_SCENARIOS_2: 0.051760 percent
C_DISCOUNT_SCENARIOS: 0.103520 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.103520 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 26.604555 percent –Issue
LKP_C_BT_AT_TO_PROMOTION_2: 0.025880 percent
LKP_C_BT_AT_TO_PROMOTION_3: 0.077640 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.103520 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.051760 percent
LKP_C_TARIFF_TIME: 0.051760 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.077640 percent
EXP_C_DISCOUNT_SCENARIOS_2: 0.129400 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.025880 percent
C_FAMILY_OFFER_DISCOUNT: 0.077640 percent
LKP_D_ESERV_BALANCE_TYPE_6: 0.077640 percent
LKP_C_BT_AT_TO_PROMOTION_6: 0.103520 percent
LKP_D_ROAMING_CALL_TYPE: 0.103520 percent
LKP_D_PREPAID_TERMINATION_IND: 0.207039 percent
LKP_D_ZONE_DESTINATION_10: 0.051760 percent
EXPTRANS11: 0.051760 percent
LKP_D_ZONE_DESTINATION_2: 0.077640 percent
EXPTRANS4: 0.077640 percent
LKP_D_ZONE_DESTINATION_12: 0.051760 percent
EXPTRANS2: 0.698758 percent
LKP_D_ZONE_DESTINATION_7: 0.025880 percent
LKP_D_ZONE_DESTINATION_8: 0.025880 percent
LKP_D_ZONE_DESTINATION_11: 0.051760 percent
LKP_D_ZONE_DESTINATION_4: 0.051760 percent
LKP_D_ZONE_DESTINATION_5: 0.077640 percent
LKP_D_ZONE_DESTINATION_13: 0.077640 percent
LKP_D_ZONE_DESTINATION_6: 0.051760 percent
LKP_D_ZONE_DESTINATION_9: 0.129400 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 48.861284 percent –Issue
Shortcut_to_mplt_LKP_DContractKey.EXPTRANS: 0.025880 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.439959 percent
EXP_CO_ID: 0.232919 percent
SMS3PGW: 0.025880 percent
LKP_D_WIFI_SITE: 0.025880 percent
LKP_D_SERVICE1: 0.051760 percent
LKP_D_ACCOUNT_TYPE: 0.025880 percent
EXP_WIFI_VALUES: 0.155280 percent
LKP_D_RATEPLAN: 0.103520 percent
LKP_C_YOUTH_DISCOUNT: 0.077640 percent
EXPTRANS5: 0.155280 percent
C_SMS_DISCOUNT: 0.025880 percent
C_SMS_DISCOUNT_SMS2FREE: 0.051760 percent
LKP_D_ZONE_DESTINATION_10_TN: 0.077640 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 15.916149 percent –Issue
EXPTRANS: 1.733954 percent
EXPTRANS1: 1.656315 percent
LKP_ESERVSRV_BSCSSRV: 0.025880 percent
LKP_D_SERVICE: 0.103520 percent
LKP_D_ESERV_BALANCE_TYPE_1: 0.025880 percent
LKP_D_ESERV_BALANCE_TYPE_2: 0.051760 percent
LKP_D_ESERV_BALANCE_TYPE_3: 0.051760 percent
LKP_D_ESERV_BALANCE_TYPE_4: 0.103520 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.077640 percent
LKP_CALL_RATE_UOM: 0.051760 percent
EXP_DISCOUNT_PROCESS: 0.258799 percent
Thread [READER_1_1_2] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8043.859422] secs
Total Idle Time = [7351.270989] secs
Busy Percentage = [8.610151]
Thread [TRANSF_1_1_2] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8043.390875] secs
Total Idle Time = [401.644627] secs
Busy Percentage = [95.006526]
Thread work time breakdown:
EXPTRANS3: 0.105932 percent
C_DISCOUNT_SCENARIOS_1: 0.052966 percent
C_DISCOUNT_SCENARIOS_2: 0.105932 percent
C_DISCOUNT_SCENARIOS: 0.052966 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.105932 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 24.417373 percent
LKP_C_BT_AT_TO_PROMOTION_2: 0.105932 percent
LKP_C_BT_AT_TO_PROMOTION_3: 0.026483 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.052966 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.079449 percent
LKP_C_TARIFF_TIME: 0.079449 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.052966 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.185381 percent
C_FAMILY_OFFER_DISCOUNT: 0.132415 percent
LKP_C_BT_AT_TO_PROMOTION_6: 0.052966 percent
LKP_D_ROAMING_CALL_TYPE: 0.052966 percent
LKP_D_PREPAID_TERMINATION_IND: 0.185381 percent
LKP_D_ZONE_DESTINATION_10: 0.132415 percent
EXPTRANS11: 0.052966 percent
LKP_D_ZONE_DESTINATION_2: 0.026483 percent
EXPTRANS4: 0.185381 percent
LKP_D_ZONE_DESTINATION_12: 0.105932 percent
EXPTRANS2: 0.794492 percent
LKP_D_ZONE_DESTINATION_7: 0.079449 percent
LKP_D_ZONE_DESTINATION_8: 0.052966 percent
LKP_D_ZONE_DESTINATION_11: 0.105932 percent
LKP_D_ZONE_DESTINATION_3: 0.026483 percent
LKP_D_ZONE_DESTINATION_4: 0.079449 percent
LKP_D_ZONE_DESTINATION_5: 0.026483 percent
LKP_D_ZONE_DESTINATION_13: 0.026483 percent
LKP_D_ZONE_DESTINATION_6: 0.105932 percent
LKP_D_ZONE_DESTINATION_9: 0.105932 percent
EXP_SetFamilyId: 0.052966 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 51.324153 percent
Shortcut_to_mplt_LKP_DContractKey.EXPTRANS: 0.079449 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.397246 percent
EXP_CO_ID: 0.264831 percent
C_3PGW_EVENT_NAME_LOOKUP: 0.052966 percent
LKP_D_WIFI_SITE: 0.238347 percent
EXP_DEDUCE_SERVICE_SHDES: 0.026483 percent
LKP_D_ACCOUNT_TYPE: 0.052966 percent
EXP_WIFI_VALUES: 0.185381 percent
LKP_D_RATEPLAN: 0.079449 percent
LKP_C_YOUTH_DISCOUNT: 0.052966 percent
Filter_National800_Postapid: 0.158898 percent
EXPTRANS5: 0.052966 percent
C_SMS_DISCOUNT: 0.052966 percent
C_SMS_DISCOUNT_SMS2FREE: 0.052966 percent
LKP_D_ZONE_DESTINATION_10_TN: 0.052966 percent
Shortcut_to_mplt_LKP_MResourceLookup.Lookup_Output: 0.026483 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 15.545551 percent
EXPTRANS: 1.350636 percent
EXPTRANS1: 1.430085 percent
LKP_D_SERVICE: 0.052966 percent
LKP_D_ESERV_BALANCE_TYPE_1: 0.079449 percent
LKP_D_ESERV_BALANCE_TYPE_2: 0.026483 percent
LKP_D_ESERV_BALANCE_TYPE_3: 0.052966 percent
LKP_D_ESERV_BALANCE_TYPE_4: 0.026483 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.079449 percent
LKP_CALL_RATE_UOM: 0.079449 percent
LKP_D_DATE: 0.079449 percent
EXP_DISCOUNT_PROCESS: 0.238347 percent
Thread [READER_1_1_3] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8081.738819] secs
Total Idle Time = [6973.793559] secs
Busy Percentage = [13.709244]
Thread [TRANSF_1_1_3] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8044.402524] secs
Total Idle Time = [661.651047] secs
Busy Percentage = [91.775013]
Thread work time breakdown:
EXPTRANS3: 0.138466 percent
C_DISCOUNT_SCENARIOS_1: 0.055386 percent
C_DISCOUNT_SCENARIOS_2: 0.055386 percent
C_DISCOUNT_SCENARIOS: 0.055386 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.055386 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 27.582387 percent
LKP_C_BT_AT_TO_PROMOTION_2: 0.027693 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.027693 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.166159 percent
LKP_C_TARIFF_TIME: 0.138466 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.138466 percent
EXP_C_DISCOUNT_SCENARIOS_2: 0.138466 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.166159 percent
C_FAMILY_OFFER_DISCOUNT: 0.110773 percent
LKP_D_ESERV_BALANCE_TYPE_6: 0.027693 percent
LKP_D_PREPAID_TERMINATION_IND: 0.166159 percent
LKP_D_ZONE_DESTINATION_10: 0.110773 percent
EXPTRANS11: 0.055386 percent
EXPTRANS4: 0.083079 percent
LKP_D_ZONE_DESTINATION_12: 0.027693 percent
EXPTRANS2: 0.830795 percent
LKP_D_ZONE_DESTINATION_7: 0.027693 percent
LKP_D_ZONE_DESTINATION_8: 0.027693 percent
LKP_D_ZONE_DESTINATION_3: 0.055386 percent
LKP_D_ZONE_DESTINATION_5: 0.055386 percent
LKP_D_ZONE_DESTINATION_13: 0.027693 percent
EXP_SetFamilyId: 0.055386 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 47.992246 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.332318 percent
EXP_CO_ID: 0.193852 percent
C_3PGW_EVENT_NAME_LOOKUP: 0.083079 percent
SMS3PGW: 0.027693 percent
LKP_D_WIFI_SITE: 0.055386 percent
EXP_DEDUCE_SERVICE_SHDES: 0.027693 percent
EXP_WIFI_VALUES: 0.249238 percent
LKP_D_RATEPLAN: 0.193852 percent
LKP_C_YOUTH_DISCOUNT: 0.055386 percent
Filter_National800_Postapid: 0.166159 percent
EXPTRANS5: 0.055386 percent
C_SMS_DISCOUNT: 0.027693 percent
C_SMS_DISCOUNT_SMS2FREE: 0.055386 percent
LKP_D_ZONE_DESTINATION_10_TN: 0.055386 percent
Shortcut_to_mplt_LKP_MResourceLookup.Lookup_Output: 0.027693 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 16.034340 percent
EXPTRANS: 1.329272 percent
EXPTRANS1: 1.744669 percent
LKP_ESERVSRV_BSCSSRV: 0.027693 percent
LKP_D_SERVICE: 0.083079 percent
LKP_D_ESERV_BALANCE_TYPE_2: 0.027693 percent
LKP_D_ESERV_BALANCE_TYPE_3: 0.110773 percent
LKP_D_ESERV_BALANCE_TYPE_4: 0.027693 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.110773 percent
LKP_CALL_RATE_UOM: 0.055386 percent
LKP_D_DATE: 0.055386 percent
EXP_DISCOUNT_PROCESS: 0.387704 percent
Thread [READER_1_1_4] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8042.880813] secs
Total Idle Time = [7363.644123] secs
Busy Percentage = [8.445192]
Thread [TRANSF_1_1_4] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8042.423685] secs
Total Idle Time = [376.782841] secs
Busy Percentage = [95.315059]
Thread work time breakdown:
EXPTRANS3: 0.132066 percent
C_DISCOUNT_SCENARIOS_1: 0.079239 percent
C_DISCOUNT_SCENARIOS_2: 0.052826 percent
C_DISCOUNT_SCENARIOS: 0.052826 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.158479 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 26.281035 percent
LKP_C_BT_AT_TO_PROMOTION_2: 0.158479 percent
LKP_C_BT_AT_TO_PROMOTION_3: 0.026413 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.026413 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.079239 percent
LKP_C_TARIFF_TIME: 0.184892 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.132066 percent
EXP_C_DISCOUNT_SCENARIOS_2: 0.184892 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.184892 percent
C_FAMILY_OFFER_DISCOUNT: 0.026413 percent
LKP_D_ESERV_BALANCE_TYPE_6: 0.052826 percent
LKP_C_BT_AT_TO_PROMOTION_6: 0.132066 percent
LKP_D_ROAMING_CALL_TYPE: 0.158479 percent
LKP_D_PREPAID_TERMINATION_IND: 0.316957 percent
LKP_D_ZONE_DESTINATION_10: 0.079239 percent
EXPTRANS11: 0.052826 percent
LKP_D_ZONE_DESTINATION_2: 0.052826 percent
EXPTRANS4: 0.052826 percent
LKP_D_ZONE_DESTINATION_12: 0.052826 percent
EXPTRANS2: 0.581088 percent
LKP_D_ZONE_DESTINATION_7: 0.079239 percent
LKP_D_ZONE_DESTINATION_8: 0.105652 percent
LKP_D_ZONE_DESTINATION_11: 0.052826 percent
LKP_D_ZONE_DESTINATION_3: 0.052826 percent
LKP_D_ZONE_DESTINATION_4: 0.026413 percent
LKP_D_ZONE_DESTINATION_5: 0.184892 percent
LKP_D_ZONE_DESTINATION_6: 0.052826 percent
LKP_D_ZONE_DESTINATION_9: 0.026413 percent
EXP_SetFamilyId: 0.026413 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 49.471738 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.475436 percent
EXP_CO_ID: 0.237718 percent
SMS3PGW: 0.079239 percent
LKP_D_WIFI_SITE: 0.079239 percent
EXP_DEDUCE_SERVICE_SHDES: 0.026413 percent
LKP_D_SERVICE1: 0.026413 percent
LKP_D_ACCOUNT_TYPE: 0.026413 percent
EXP_WIFI_VALUES: 0.211305 percent
LKP_D_RATEPLAN: 0.079239 percent
LKP_C_YOUTH_DISCOUNT: 0.105652 percent
Filter_National800_Postapid: 0.105652 percent
EXPTRANS5: 0.052826 percent
C_SMS_DISCOUNT: 0.079239 percent
C_SMS_DISCOUNT_SMS2FREE: 0.079239 percent
LKP_D_ZONE_DESTINATION_10_TN: 0.079239 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 14.368727 percent
EXPTRANS: 1.241416 percent
EXPTRANS1: 2.165874 percent
LKP_D_SERVICE: 0.052826 percent
LKP_D_ESERV_BALANCE_TYPE_1: 0.079239 percent
LKP_D_ESERV_BALANCE_TYPE_2: 0.052826 percent
LKP_D_ESERV_BALANCE_TYPE_3: 0.052826 percent
LKP_D_ESERV_BALANCE_TYPE_4: 0.105652 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.132066 percent
LKP_CALL_RATE_UOM: 0.052826 percent
LKP_D_DATE: 0.105652 percent
EXP_DISCOUNT_PROCESS: 0.475436 percent
Thread [READER_1_1_5] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8043.446786] secs
Total Idle Time = [7403.509958] secs
Busy Percentage = [7.956003]
Thread [TRANSF_1_1_5] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8043.016201] secs
Total Idle Time = [338.911134] secs
Busy Percentage = [95.786268]
Thread work time breakdown:
EXPTRANS3: 0.079177 percent
C_DISCOUNT_SCENARIOS_1: 0.079177 percent
Shortcut_to_mplt_LKP_DCustomer.Lookup_Output: 0.026392 percent
C_DISCOUNT_SCENARIOS_2: 0.052784 percent
C_DISCOUNT_SCENARIOS: 0.052784 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.105569 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 25.917129 percent
LKP_C_BT_AT_TO_PROMOTION_2: 0.052784 percent
LKP_C_BT_AT_TO_PROMOTION_3: 0.079177 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.105569 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.052784 percent
LKP_C_TARIFF_TIME: 0.184745 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.158353 percent
EXP_C_DISCOUNT_SCENARIOS_2: 0.079177 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.184745 percent
C_FAMILY_OFFER_DISCOUNT: 0.184745 percent
LKP_D_ESERV_BALANCE_TYPE_6: 0.105569 percent
LKP_C_BT_AT_TO_PROMOTION_6: 0.131961 percent
FIL_JUST_INSERTS: 0.026392 percent
LKP_D_ROAMING_CALL_TYPE: 0.079177 percent
LKP_D_PREPAID_TERMINATION_IND: 0.105569 percent
LKP_D_ZONE_DESTINATION_10: 0.105569 percent
LKP_D_ZONE_DESTINATION_2: 0.026392 percent
EXPTRANS4: 0.158353 percent
LKP_D_ZONE_DESTINATION_12: 0.052784 percent
EXPTRANS2: 0.870942 percent
LKP_D_ZONE_DESTINATION_8: 0.052784 percent
LKP_D_ZONE_DESTINATION_11: 0.105569 percent
LKP_D_ZONE_DESTINATION_3: 0.079177 percent
LKP_D_ZONE_DESTINATION_4: 0.026392 percent
LKP_D_ZONE_DESTINATION_5: 0.079177 percent
LKP_D_ZONE_DESTINATION_13: 0.026392 percent
LKP_D_ZONE_DESTINATION_6: 0.052784 percent
Shortcut_to_mplt_LKP_DContractKey.Lookup_Output: 0.052784 percent
EXP_SetFamilyId: 0.079177 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 49.775666 percent
Shortcut_to_mplt_LKP_DContractKey.EXPTRANS: 0.026392 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.448667 percent
EXP_CO_ID: 0.184745 percent
SMS3PGW: 0.026392 percent
LKP_D_WIFI_SITE: 0.131961 percent
LKP_D_SERVICE1: 0.052784 percent
LKP_D_ACCOUNT_TYPE: 0.079177 percent
EXP_WIFI_VALUES: 0.184745 percent
LKP_D_RATEPLAN: 0.184745 percent
LKP_C_YOUTH_DISCOUNT: 0.052784 percent
Filter_National800_Postapid: 0.079177 percent
EXPTRANS5: 0.026392 percent
C_SMS_DISCOUNT: 0.026392 percent
C_SMS_DISCOUNT_SMS2FREE: 0.052784 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 14.779625 percent
EXPTRANS: 1.504355 percent
EXPTRANS1: 1.794669 percent
LKP_ESERVSRV_BSCSSRV: 0.105569 percent
LKP_D_SERVICE: 0.052784 percent
LKP_D_ESERV_BALANCE_TYPE_1: 0.131961 percent
LKP_D_ESERV_BALANCE_TYPE_2: 0.052784 percent
LKP_D_ESERV_BALANCE_TYPE_3: 0.079177 percent
LKP_D_ESERV_BALANCE_TYPE_4: 0.079177 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.079177 percent
LKP_CALL_RATE_UOM: 0.052784 percent
LKP_D_DATE: 0.026392 percent
EXP_DISCOUNT_PROCESS: 0.316706 percent
Thread [READER_1_1_6] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8042.965923] secs
Total Idle Time = [7383.018789] secs
Busy Percentage = [8.205271]
Thread [TRANSF_1_1_6] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8042.523822] secs
Total Idle Time = [369.542577] secs
Busy Percentage = [95.405142]
Thread work time breakdown:
EXPTRANS3: 0.079470 percent
C_DISCOUNT_SCENARIOS_1: 0.079470 percent
C_DISCOUNT_SCENARIOS_2: 0.026490 percent
C_DISCOUNT_SCENARIOS: 0.105960 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.132450 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 25.271523 percent
LKP_C_BT_AT_TO_PROMOTION_2: 0.079470 percent
LKP_C_BT_AT_TO_PROMOTION_3: 0.026490 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.052980 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.079470 percent
LKP_C_TARIFF_TIME: 0.132450 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.079470 percent
EXP_C_DISCOUNT_SCENARIOS_2: 0.238411 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.132450 percent
C_FAMILY_OFFER_DISCOUNT: 0.052980 percent
LKP_D_ESERV_BALANCE_TYPE_6: 0.079470 percent
LKP_C_BT_AT_TO_PROMOTION_6: 0.052980 percent
LKP_D_ROAMING_CALL_TYPE: 0.105960 percent
LKP_D_PREPAID_TERMINATION_IND: 0.211921 percent
LKP_D_ZONE_DESTINATION_10: 0.105960 percent
EXPTRANS11: 0.052980 percent
LKP_D_ZONE_DESTINATION_2: 0.105960 percent
EXPTRANS4: 0.105960 percent
LKP_D_ZONE_DESTINATION_12: 0.105960 percent
EXPTRANS2: 0.741722 percent
LKP_D_ZONE_DESTINATION_8: 0.079470 percent
LKP_D_ZONE_DESTINATION_11: 0.079470 percent
LKP_D_ZONE_DESTINATION_3: 0.158940 percent
LKP_D_ZONE_DESTINATION_4: 0.052980 percent
LKP_D_ZONE_DESTINATION_5: 0.079470 percent
LKP_D_ZONE_DESTINATION_13: 0.052980 percent
LKP_D_ZONE_DESTINATION_6: 0.079470 percent
LKP_D_ZONE_DESTINATION_9: 0.052980 percent
Shortcut_to_mplt_LKP_DContractKey.Lookup_Output: 0.026490 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 50.119205 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.476821 percent
EXP_CO_ID: 0.291391 percent
C_3PGW_EVENT_NAME_LOOKUP: 0.052980 percent
SMS3PGW: 0.052980 percent
LKP_D_WIFI_SITE: 0.026490 percent
EXP_DEDUCE_SERVICE_SHDES: 0.052980 percent
LKP_D_SERVICE1: 0.052980 percent
LKP_D_ACCOUNT_TYPE: 0.026490 percent
EXP_WIFI_VALUES: 0.264901 percent
LKP_D_RATEPLAN: 0.052980 percent
LKP_C_YOUTH_DISCOUNT: 0.052980 percent
Filter_National800_Postapid: 0.132450 percent
EXPTRANS5: 0.052980 percent
C_SMS_DISCOUNT: 0.026490 percent
C_SMS_DISCOUNT_SMS2FREE: 0.026490 percent
LKP_D_ZONE_DESTINATION_10_TN: 0.079470 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 15.417219 percent
EXPTRANS: 1.509934 percent
EXPTRANS1: 1.430464 percent
LKP_ESERVSRV_BSCSSRV: 0.052980 percent
LKP_D_SERVICE: 0.052980 percent
LKP_D_ESERV_BALANCE_TYPE_1: 0.158940 percent
LKP_D_ESERV_BALANCE_TYPE_3: 0.079470 percent
LKP_D_ESERV_BALANCE_TYPE_4: 0.052980 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.079470 percent
LKP_CALL_RATE_UOM: 0.158940 percent
LKP_D_DATE: 0.052980 percent
EXP_DISCOUNT_PROCESS: 0.211921 percent
Thread [READER_1_1_7] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8039.580460] secs
Total Idle Time = [7384.609052] secs
Busy Percentage = [8.146836]
Thread [TRANSF_1_1_7] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8039.117916] secs
Total Idle Time = [360.756425] secs
Busy Percentage = [95.512487]
Thread work time breakdown:
EXPTRANS3: 0.079386 percent
C_DISCOUNT_SCENARIOS_1: 0.052924 percent
C_DISCOUNT_SCENARIOS_2: 0.079386 percent
C_DISCOUNT_SCENARIOS: 0.105848 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.185234 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 24.424451 percent
LKP_C_BT_AT_TO_PROMOTION_2: 0.026462 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.026462 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.238158 percent
LKP_C_TARIFF_TIME: 0.052924 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.052924 percent
EXP_C_DISCOUNT_SCENARIOS_2: 0.211696 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.105848 percent
C_FAMILY_OFFER_DISCOUNT: 0.079386 percent
LKP_D_ESERV_BALANCE_TYPE_6: 0.026462 percent
LKP_C_BT_AT_TO_PROMOTION_6: 0.052924 percent
FIL_JUST_INSERTS: 0.026462 percent
LKP_D_ROAMING_CALL_TYPE: 0.105848 percent
LKP_D_PREPAID_TERMINATION_IND: 0.158772 percent
LKP_D_ZONE_DESTINATION_10: 0.105848 percent
EXPTRANS11: 0.026462 percent
LKP_D_ZONE_DESTINATION_2: 0.026462 percent
EXPTRANS4: 0.211696 percent
LKP_D_ZONE_DESTINATION_12: 0.052924 percent
EXPTRANS2: 0.926171 percent
LKP_D_ZONE_DESTINATION_7: 0.158772 percent
LKP_D_ZONE_DESTINATION_8: 0.026462 percent
LKP_D_ZONE_DESTINATION_11: 0.132310 percent
LKP_D_ZONE_DESTINATION_3: 0.079386 percent
LKP_D_ZONE_DESTINATION_4: 0.079386 percent
LKP_D_ZONE_DESTINATION_5: 0.052924 percent
LKP_D_ZONE_DESTINATION_13: 0.026462 percent
LKP_D_ZONE_DESTINATION_6: 0.105848 percent
LKP_D_ZONE_DESTINATION_9: 0.105848 percent
EXP_SetFamilyId: 0.026462 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 50.807092 percent
Shortcut_to_mplt_LKP_DContractKey.EXPTRANS: 0.026462 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.476316 percent
EXP_CO_ID: 0.185234 percent
C_3PGW_EVENT_NAME_LOOKUP: 0.026462 percent
SMS3PGW: 0.079386 percent
LKP_D_WIFI_SITE: 0.105848 percent
LKP_D_SERVICE1: 0.026462 percent
LKP_D_ACCOUNT_TYPE: 0.026462 percent
EXP_WIFI_VALUES: 0.052924 percent
LKP_D_RATEPLAN: 0.105848 percent
LKP_C_YOUTH_DISCOUNT: 0.105848 percent
Filter_National800_Postapid: 0.052924 percent
C_SMS_DISCOUNT: 0.026462 percent
C_SMS_DISCOUNT_SMS2FREE: 0.079386 percent
LKP_D_ZONE_DESTINATION_10_TN: 0.052924 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 15.797830 percent
EXPTRANS: 1.323101 percent
EXPTRANS1: 1.587722 percent
LKP_ESERVSRV_BSCSSRV: 0.026462 percent
LKP_D_SERVICE: 0.026462 percent
LKP_D_ESERV_BALANCE_TYPE_1: 0.052924 percent
LKP_D_ESERV_BALANCE_TYPE_2: 0.052924 percent
LKP_D_ESERV_BALANCE_TYPE_4: 0.052924 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.079386 percent
LKP_CALL_RATE_UOM: 0.079386 percent
LKP_D_DATE: 0.052924 percent
EXP_DISCOUNT_PROCESS: 0.396930 percent
Thread [READER_1_1_8] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8043.673507] secs
Total Idle Time = [7278.149363] secs
Busy Percentage = [9.517096]
Thread [TRANSF_1_1_8] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8043.206278] secs
Total Idle Time = [371.757151] secs
Busy Percentage = [95.377998]
Thread work time breakdown:
EXPTRANS3: 0.054083 percent
C_DISCOUNT_SCENARIOS_1: 0.162250 percent
Shortcut_to_mplt_LKP_DCustomer.Lookup_Output: 0.027042 percent
C_DISCOUNT_SCENARIOS_2: 0.081125 percent
C_DISCOUNT_SCENARIOS: 0.081125 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.054083 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 25.256896 percent
LKP_C_BT_AT_TO_PROMOTION_2: 0.027042 percent
LKP_C_BT_AT_TO_PROMOTION_3: 0.054083 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.081125 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.108167 percent
LKP_C_TARIFF_TIME: 0.189292 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.108167 percent
EXP_C_DISCOUNT_SCENARIOS_2: 0.054083 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.135208 percent
C_FAMILY_OFFER_DISCOUNT: 0.135208 percent
LKP_D_ESERV_BALANCE_TYPE_6: 0.027042 percent
LKP_C_BT_AT_TO_PROMOTION_6: 0.108167 percent
EXPTRANS31: 0.054083 percent
LKP_D_ROAMING_CALL_TYPE: 0.054083 percent
LKP_D_PREPAID_TERMINATION_IND: 0.189292 percent
LKP_D_ZONE_DESTINATION_10: 0.189292 percent
EXPTRANS11: 0.054083 percent
LKP_D_ZONE_DESTINATION_2: 0.027042 percent
EXPTRANS4: 0.135208 percent
LKP_D_ZONE_DESTINATION_12: 0.054083 percent
EXPTRANS2: 0.730124 percent
LKP_D_ZONE_DESTINATION_7: 0.054083 percent
LKP_D_ZONE_DESTINATION_8: 0.027042 percent
LKP_D_ZONE_DESTINATION_11: 0.027042 percent
LKP_D_ZONE_DESTINATION_4: 0.108167 percent
LKP_D_ZONE_DESTINATION_5: 0.054083 percent
LKP_D_ZONE_DESTINATION_13: 0.081125 percent
LKP_D_ZONE_DESTINATION_6: 0.135208 percent
LKP_D_ZONE_DESTINATION_9: 0.081125 percent
EXP_SetFamilyId: 0.027042 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 50.405625 percent
Shortcut_to_mplt_LKP_DContractKey.EXPTRANS: 0.027042 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.459708 percent
EXP_CO_ID: 0.243375 percent
C_3PGW_EVENT_NAME_LOOKUP: 0.054083 percent
SMS3PGW: 0.027042 percent
LKP_D_WIFI_SITE: 0.108167 percent
EXP_DEDUCE_SERVICE_SHDES: 0.027042 percent
LKP_D_SERVICE1: 0.108167 percent
LKP_D_ACCOUNT_TYPE: 0.027042 percent
EXP_WIFI_VALUES: 0.189292 percent
LKP_D_RATEPLAN: 0.054083 percent
LKP_C_YOUTH_DISCOUNT: 0.108167 percent
Filter_National800_Postapid: 0.081125 percent
EXPTRANS5: 0.054083 percent
C_SMS_DISCOUNT: 0.162250 percent
C_SMS_DISCOUNT_SMS2FREE: 0.054083 percent
LKP_D_ZONE_DESTINATION_10_TN: 0.027042 percent
Shortcut_to_mplt_LKP_MResourceLookup.Lookup_Output: 0.027042 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 15.630070 percent
EXPTRANS: 0.892374 percent
EXPTRANS1: 1.514332 percent
LKP_ESERVSRV_BSCSSRV: 0.027042 percent
LKP_D_SERVICE: 0.081125 percent
LKP_D_ESERV_BALANCE_TYPE_2: 0.108167 percent
LKP_D_ESERV_BALANCE_TYPE_3: 0.081125 percent
LKP_D_ESERV_BALANCE_TYPE_4: 0.054083 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.108167 percent
LKP_CALL_RATE_UOM: 0.081125 percent
LKP_D_DATE: 0.081125 percent
EXP_DISCOUNT_PROCESS: 0.270416 percent
Thread [READER_1_1_9] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8038.357138] secs
Total Idle Time = [7425.975230] secs
Busy Percentage = [7.618247]
Thread [TRANSF_1_1_9] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [8037.886639] secs
Total Idle Time = [318.143104] secs
Busy Percentage = [96.041956]
Thread work time breakdown:
EXPTRANS3: 0.106185 percent
C_DISCOUNT_SCENARIOS_1: 0.026546 percent
C_DISCOUNT_SCENARIOS_2: 0.132732 percent
C_DISCOUNT_SCENARIOS: 0.185824 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.185824 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 25.165915 percent
LKP_C_BT_AT_TO_PROMOTION_2: 0.106185 percent
LKP_C_BT_AT_TO_PROMOTION_3: 0.079639 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.079639 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.079639 percent
LKP_C_TARIFF_TIME: 0.159278 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.185824 percent
EXP_C_DISCOUNT_SCENARIOS_2: 0.106185 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.265463 percent
C_FAMILY_OFFER_DISCOUNT: 0.079639 percent
LKP_C_BT_AT_TO_PROMOTION_6: 0.132732 percent
LKP_D_ROAMING_CALL_TYPE: 0.053093 percent
LKP_D_PREPAID_TERMINATION_IND: 0.371649 percent
LKP_D_ZONE_DESTINATION_10: 0.132732 percent
EXPTRANS11: 0.079639 percent
LKP_D_ZONE_DESTINATION_2: 0.159278 percent
EXPTRANS4: 0.106185 percent
LKP_D_ZONE_DESTINATION_12: 0.106185 percent
EXPTRANS2: 0.530926 percent
LKP_D_ZONE_DESTINATION_7: 0.053093 percent
LKP_D_ZONE_DESTINATION_8: 0.053093 percent
LKP_D_ZONE_DESTINATION_11: 0.106185 percent
LKP_D_ZONE_DESTINATION_3: 0.079639 percent
LKP_D_ZONE_DESTINATION_4: 0.053093 percent
LKP_D_ZONE_DESTINATION_5: 0.026546 percent
LKP_D_ZONE_DESTINATION_13: 0.026546 percent
LKP_D_ZONE_DESTINATION_6: 0.106185 percent
LKP_D_ZONE_DESTINATION_9: 0.053093 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 50.464561 percent
Shortcut_to_mplt_LKP_DContractKey.EXPTRANS: 0.053093 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.345102 percent
EXP_CO_ID: 0.238917 percent
C_3PGW_EVENT_NAME_LOOKUP: 0.026546 percent
SMS3PGW: 0.053093 percent
LKP_D_WIFI_SITE: 0.106185 percent
EXP_DEDUCE_SERVICE_SHDES: 0.053093 percent
LKP_D_SERVICE1: 0.132732 percent
EXP_WIFI_VALUES: 0.132732 percent
LKP_D_RATEPLAN: 0.079639 percent
LKP_C_YOUTH_DISCOUNT: 0.079639 percent
Filter_National800_Postapid: 0.106185 percent
EXPTRANS5: 0.026546 percent
C_SMS_DISCOUNT: 0.053093 percent
C_SMS_DISCOUNT_SMS2FREE: 0.053093 percent
LKP_D_ZONE_DESTINATION_10_TN: 0.053093 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 15.396868 percent
EXPTRANS: 1.088399 percent
EXPTRANS1: 1.698965 percent
LKP_ESERVSRV_BSCSSRV: 0.026546 percent
LKP_D_SERVICE: 0.026546 percent
LKP_D_ESERV_BALANCE_TYPE_1: 0.026546 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.132732 percent
LKP_CALL_RATE_UOM: 0.079639 percent
LKP_D_DATE: 0.026546 percent
EXP_DISCOUNT_PROCESS: 0.265463 percent
Thread [READER_1_1_10] created for [the read stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [7973.441151] secs
Total Idle Time = [7621.536842] secs
Busy Percentage = [4.413456]
Thread [TRANSF_1_1_10] created for [the transformation stage] of partition point [SQ_Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP01] has completed.
Total Run Time = [7972.986244] secs
Total Idle Time = [127.116765] secs
Busy Percentage = [98.405657]
Thread work time breakdown:
EXPTRANS3: 0.128932 percent
C_DISCOUNT_SCENARIOS_1: 0.051573 percent
C_DISCOUNT_SCENARIOS_2: 0.103146 percent
C_DISCOUNT_SCENARIOS: 0.154719 percent
LKP_C_BT_AT_TO_PROMOTION_1: 0.103146 percent
Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER: 26.585869 percent
LKP_C_BT_AT_TO_PROMOTION_2: 0.051573 percent
LKP_C_BT_AT_TO_PROMOTION_3: 0.154719 percent
LKP_C_BT_AT_TO_PROMOTION_4: 0.077359 percent
LKP_C_BT_AT_TO_PROMOTION_5: 0.103146 percent
LKP_C_TARIFF_TIME: 0.128932 percent
EXP_C_DISCOUNT_SCENARIOS_DEFAULT: 0.051573 percent
EXP_C_DISCOUNT_SCENARIOS_2: 0.128932 percent
EXP_C_DISCOUNT_SCENARIOS_1: 0.206292 percent
C_FAMILY_OFFER_DISCOUNT: 0.128932 percent
LKP_D_ESERV_BALANCE_TYPE_6: 0.025786 percent
LKP_C_BT_AT_TO_PROMOTION_6: 0.077359 percent
LKP_D_ROAMING_CALL_TYPE: 0.077359 percent
LKP_D_PREPAID_TERMINATION_IND: 0.180505 percent
LKP_D_ZONE_DESTINATION_10: 0.051573 percent
EXPTRANS11: 0.025786 percent
LKP_D_ZONE_DESTINATION_2: 0.103146 percent
EXPTRANS4: 0.103146 percent
LKP_D_ZONE_DESTINATION_12: 0.103146 percent
EXPTRANS2: 0.902527 percent
LKP_D_ZONE_DESTINATION_7: 0.025786 percent
LKP_D_ZONE_DESTINATION_8: 0.051573 percent
LKP_D_ZONE_DESTINATION_11: 0.103146 percent
LKP_D_ZONE_DESTINATION_3: 0.103146 percent
LKP_D_ZONE_DESTINATION_4: 0.103146 percent
LKP_D_ZONE_DESTINATION_13: 0.077359 percent
LKP_D_ZONE_DESTINATION_6: 0.051573 percent
LKP_D_ZONE_DESTINATION_9: 0.128932 percent
Shortcut_to_mplt_LKP_DContractKey.Lookup_Output: 0.025786 percent
EXP_SetFamilyId: 0.051573 percent
Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY: 49.690562 percent
Shortcut_to_mplt_LKP_DContractKey.EXPTRANS: 0.025786 percent
LKP_H_FAMILY_OFFER_ASSIGNMENT: 0.361011 percent
EXP_CO_ID: 0.309438 percent
C_3PGW_EVENT_NAME_LOOKUP: 0.051573 percent
LKP_D_WIFI_SITE: 0.051573 percent
EXP_DEDUCE_SERVICE_SHDES: 0.025786 percent
LKP_D_SERVICE1: 0.051573 percent
EXP_WIFI_VALUES: 0.283651 percent
LKP_D_RATEPLAN: 0.103146 percent
LKP_C_YOUTH_DISCOUNT: 0.051573 percent
Filter_National800_Postapid: 0.128932 percent
EXPTRANS5: 0.077359 percent
C_SMS_DISCOUNT: 0.077359 percent
C_SMS_DISCOUNT_SMS2FREE: 0.128932 percent
LKP_D_ZONE_DESTINATION_10_TN: 0.051573 percent
Shortcut_to_mplt_LKP_MResourceLookup.Lookup_Output: 0.025786 percent
Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP: 14.079422 percent
EXPTRANS: 1.237751 percent
EXPTRANS1: 1.650335 percent
LKP_D_SERVICE: 0.103146 percent
LKP_D_ESERV_BALANCE_TYPE_1: 0.128932 percent
LKP_D_ESERV_BALANCE_TYPE_2: 0.025786 percent
LKP_D_ESERV_BALANCE_TYPE_3: 0.051573 percent
LKP_D_ESERV_BALANCE_TYPE_4: 0.077359 percent
LKP_D_ESERV_BALANCE_TYPE_5: 0.077359 percent
LKP_CALL_RATE_UOM: 0.103146 percent
LKP_D_DATE: 0.103146 percent
EXP_DISCOUNT_PROCESS: 0.335224 percent
Thread [WRITER_1_*_1] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [7970.798817] secs
Total Idle Time = [7635.067137] secs
Busy Percentage = [4.212020]
Thread [WRITER_1_*_2] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [8005.392949] secs
Total Idle Time = [7826.863324] secs
Busy Percentage = [2.230117]
Thread [WRITER_1_*_3] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [8035.285412] secs
Total Idle Time = [7862.034784] secs
Busy Percentage = [2.156123]
Thread [WRITER_1_*_4] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [8004.837249] secs
Total Idle Time = [7820.322445] secs
Busy Percentage = [2.305041]
Thread [WRITER_1_*_5] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [8005.218130] secs
Total Idle Time = [7670.070759] secs
Busy Percentage = [4.186611]
Thread [WRITER_1_*_6] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [8006.055964] secs
Total Idle Time = [7826.570591] secs
Busy Percentage = [2.241870]
Thread [WRITER_1_*_7] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [8001.146298] secs
Total Idle Time = [7668.052875] secs
Busy Percentage = [4.163071]
Thread [WRITER_1_*_8] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [8004.774460] secs
Total Idle Time = [7802.559970] secs
Busy Percentage = [2.526173]
Thread [WRITER_1_*_9] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [7999.657870] secs
Total Idle Time = [7665.230026] secs
Busy Percentage = [4.180527]
Thread [WRITER_1_*_10] created for [the write stage] of partition point [Shortcut_to_D_PREPAID_TERMINATION_IND, Shortcut_to_M_DETAIL_PREP_TRAFFIC_TMP03] has completed.
Total Run Time = [7935.113489] secs
Total Idle Time = [7636.456999] secs
Busy Percentage = [3.763733]

**************
So by looking at the session log, we could make out that a of 10 was used and most of the time was taken by the transformation threads. And withing the transformation threads, most of the time was taken by these 3 lookup transformations in decreasing order of time consumed
– Shortcut_to_mplt_LKP_DContractKey.D_CONTRACT_KEY
– Shortcut_to_mplt_LKP_DCustomer.D_CUSTOMER
– Shortcut_to_mplt_LKP_MResourceLookup.M_RESOURCE_LOOKUP

A quick check of the transformation jobs revealed that the 3 tables involved in the lookup CONTRACT_KEY, CUSTOMER & RESOURCE had data in GB’s with million of rows. Changing these 3 lookups into a straight SQL join reduced the total time consumed by almost 1/4th.
I also found this good note related to Lookup tuning – Informatica PowerCenter Lookup performance tips

Create a free website or blog at WordPress.com.