Example 1: Create Index Taking Too Long


Problem Description

CustomerA was creating indexes for a large table in its database, but the time required to create the index appeared to be excessive. The following is the db2batch output, which shows the time required to create the index:

  ---------------------------------------------   Statement number: 1   create index x1 on staff (id)   Elapsed Time is:           1068.922   seconds   ---------------------------------------------  

Problem Analysis and Resolution

Step 1: Examine the Database and Database Manager Configuration Parameters
Database manager configuration

The three parameters in the database manager configuration that typically have a big impact on the create index operation are the SHEAPTHRES, MAX_QUERYDEGREE, and INTRA_PARALLEL, and these parameters are highlighted in bold below. In this case, intra-partition parallelism was disabled; therefore, the index creation could not take advantage of the multiple CPUs in the server. If intra-partition parallelism is enabled, there will be sort heap used during the index creation in all subagent processes; therefore, the sort heap threshold (SHEAPTHRES) may also need to be increased.

  Node type = Database Server with local clients   Database manager configuration release level            = 0x0a00   CPU speed (millisec/instruction)             (CPUSPEED) = 4.000000e-05   Max number of concurrently active databases     (NUMDB) = 8   Data Links support                          (DATALINKS) = NO   Federated Database System Support           (FEDERATED) = NO   Transaction processor monitor name        (TP_MON_NAME) =   Default charge-back account           (DFT_ACCOUNT_STR) =   Java Development Kit installation path       (JDK_PATH) = /wsdb/v81/   bldsupp/AIX/jdk1.3.0   Diagnostic error capture level              (DIAGLEVEL) = 3   Notify Level                              (NOTIFYLEVEL) = 3   Diagnostic data directory path               (DIAGPATH) =   Default database monitor switches   Buffer pool                         (DFT_MON_BUFPOOL) = OFF   Lock                                   (DFT_MON_LOCK) = OFF   Sort                                   (DFT_MON_SORT) = OFF   Statement                              (DFT_MON_STMT) = OFF   Table                                 (DFT_MON_TABLE) = OFF   Timestamp                         (DFT_MON_TIMESTAMP) = ON   Unit of work                            (DFT_MON_UOW) = OFF   Monitor health of instance and databases   (HEALTH_MON) = OFF   SYSADM group name                        (SYSADM_GROUP) = BUILD   SYSCTRL group name                      (SYSCTRL_GROUP) =   SYSMAINT group name                    (SYSMAINT_GROUP) =   Database manager authentication        (AUTHENTICATION) = SERVER   Cataloging allowed without authority   (CATALOG_NOAUTH) = YES   Trust all clients                      (TRUST_ALLCLNTS) = YES   Trusted client authentication          (TRUST_CLNTAUTH) = CLIENT   Use SNA authentication                   (USE_SNA_AUTH) = NO   Bypass federated authentication            (FED_NOAUTH) = NO   Default database path                       (DFTDBPATH) = /home/dsnow   Database monitor heap size (4KB)          (MON_HEAP_SZ) = 90   Java Virtual Machine heap size (4KB)     (JAVA_HEAP_SZ) = 1024   Audit buffer size (4KB)                  (AUDIT_BUF_SZ) = 0   Size of instance shared memory (4KB)  (INSTANCE_MEMORY) = AUTOMATIC   Backup buffer default size (4KB)            (BACKBUFSZ) = 1024   Restore buffer default size (4KB)           (RESTBUFSZ) = 1024    Sort heap threshold (4KB)                  (SHEAPTHRES) = 20000    Directory cache support                     (DIR_CACHE) = YES   Application support layer heap size (4KB)   (ASLHEAPSZ) = 15   Max requester I/O block size (bytes)         (RQRIOBLK) = 32767   Query heap size (4KB)                   (QUERY_HEAP_SZ) = 1000   DRDA services heap size (4KB)            (DRDA_HEAP_SZ) = 128   Priority of agents                           (AGENTPRI) = SYSTEM   Max number of existing agents               (MAXAGENTS) = 200   Agent pool size                        (NUM_POOLAGENTS) = 100(calculated)   Initial number of agents in pool       (NUM_INITAGENTS) = 0   Max number of coordinating agents     (MAX_COORDAGENTS) = MAXAGENTS   Max no. of concurrent coordinating agents  (MAXCAGENTS) = MAX_COORDAGENTS   Max number of client connections      (MAX_CONNECTIONS) = MAX_COORDAGENTS   Keep fenced process                        (KEEPFENCED) = YES   Number of pooled fenced processes         (FENCED_POOL) = MAX_COORDAGENTS   Initialize fenced process with JVM     (INITFENCED_JVM) = NO   Initial number of fenced processes     (NUM_INITFENCED) = 0   Index re-creation time                       (INDEXREC) = RESTART   Transaction manager database name         (TM_DATABASE) = 1ST_CONN   Transaction resync interval (sec)     (RESYNC_INTERVAL) = 180   SPM name                                     (SPM_NAME) =   SPM log size                          (SPM_LOG_FILE_SZ) = 256   SPM resync agent limit                 (SPM_MAX_RESYNC) = 20   SPM log path                             (SPM_LOG_PATH) =   TCP/IP Service name                          (SVCENAME) =   Discovery mode                               (DISCOVER) = SEARCH   Discovery communication protocols       (DISCOVER_COMM) =   Discover server instance                (DISCOVER_INST) = ENABLE    Maximum query degree of parallelism   (MAX_QUERYDEGREE) = ANY     Enable intra-partition parallelism     (INTRA_PARALLEL) = NO    No. of int. communication buffers(4KB)(FCM_NUM_BUFFERS) = 512  
Database configuration for database sample

The three parameters in the database manager configuration that typically have a big impact on the create index operation are the LOGBUFSZ, SORTHEAP, and BUFFPAGE, and these parameters are highlighted in bold below.

  • The log buffer size (LOGBUFSZ) is important because the create index operation will cause log records to be created. In this case, the log buffer was very small and had to be increased.

  • The sort list heap (SORTHEAP) is used to sort the index keys while creating an index. Because the table was large, the sort heap was also increased so that the sorting need not spill to a temp table.

    • On AIX, also verify the ulimit for the instance owner to ensure it is not too small, causing sort overflows. In this case, the operating system was not AIX, so this was not the cause.

  • In this case, the default buffer pool size (BUFFPAGE) is 1,000 4-KB pages. To determine the real size of the buffer pool, use the following statement:

      select * from syscat.bufferpools  
    • In this case, there was only one buffer pool (IBMDEFAULTBP), and it had a size of 300,000 4-KB pages.

    • This was done on a 32-bit instance of DB2, so the size of the buffer pool could not have been increased much higher without hitting the operating system limitations.

[View full width]
 
[View full width]
Database configuration release level = 0x0a00 Database release level = 0x0a00 Database territory = US Database code page = 819 Database code set = ISO8859-1 Database country/region code = 1 Dynamic SQL Query management (DYN_QUERY_MGMT) = DISABLE Discovery support for this database (DISCOVER_DB) = ENABLE Default query optimization class (DFT_QUERYOPT) = 5 Degree of parallelism (DFT_DEGREE) = 1 Continue upon arithmetic exceptions (DFT_SQLMATHWARN) = NO Default refresh age (DFT_REFRESH_AGE) = 0 Number of frequent values retained (NUM_FREQVALUES) = 10 Number of quantiles retained (NUM_QUANTILES) = 20 Backup pending = NO Database is consistent = NO Rollforward pending = NO Restore pending = NO Multi-page file allocation enabled = NO Log retain for recovery status = NO User exit for logging status = NO Data Links Token Expiry Interval (sec) (DL_EXPINT) = 60 Data Links Write Token Init Expiry Intvl(DL_WT_IEXPINT) = 60 Data Links Number of Copies (DL_NUM_COPIES) = 1 Data Links Time after Drop (days) (DL_TIME_DROP) = 1 Data Links Token in Uppercase (DL_UPPER) = NO Data Links Token Algorithm (DL_TOKEN) = MAC0 Database heap (4KB) (DBHEAP) = 1200 Size of database shared memory (4KB) (DATABASE_MEMORY) = AUTOMATIC Catalog cache size (4KB) (CATALOGCACHE_SZ) = (MAXAPPLS*4) Log buffer size (4KB) (LOGBUFSZ) = 8 Utilities heap size (4KB) (UTIL_HEAP_SZ) = 5000 Buffer pool size (pages) (BUFFPAGE) = 1000 Extended storage segments size (4KB) (ESTORE_SEG_SZ) = 16000 Number of extended storage segments (NUM_ESTORE_SEGS) = 0 Max storage for lock list (4KB) (LOCKLIST) = 100 Max size of appl. group mem set (4KB) (APPGROUP_MEM_SZ) = 20000 Percent of mem for appl. group heap (GROUPHEAP_RATIO) = 70 Max appl. control heap size (4KB) (APP_CTL_HEAP_SZ) = 128 Sort heap thres for shared sorts (4KB) (SHEAPTHRES_SHR) = (SHEAPTHRES) Sort list heap (4KB) (SORTHEAP) = 256 SQL statement heap (4KB) (STMTHEAP) = 4096 Default application heap (4KB) (APPLHEAPSZ) = 256 Package cache size (4KB) (PCKCACHESZ) = (MAXAPPLS*8) Statistics heap size (4KB) (STAT_HEAP_SZ) = 4384 Interval for checking deadlock (ms) (DLCHKTIME) = 10000 Percent. of lock lists per application (MAXLOCKS) = 10 Lock timeout (sec) (LOCKTIMEOUT) = -1 Changed pages threshold (CHNGPGS_THRESH) = 60 Number of asynchronous page cleaners (NUM_IOCLEANERS) = 1 Number of I/O servers (NUM_IOSERVERS) = 1 Index sort flag (INDEXSORT) = YES Sequential detect flag (SEQDETECT) = YES Default prefetch size (pages) (DFT_PREFETCH_SZ) = 32 Track modified pages (TRACKMOD) = OFF Default number of containers = 1 Default tablespace extentsize (pages) (DFT_EXTENT_SZ) = 32 Max number of active applications (MAXAPPLS) = AUTOMATIC Average number of active applications (AVG_APPLS) = 1 Max DB files open per application (MAXFILOP) = 64 Log file size (4KB) (LOGFILSIZ) = 1000 Number of primary log files (LOGPRIMARY) = 3 Number of secondary log files (LOGSECOND) = 2 Changed path to log files (NEWLOGPATH) = Path to log files = /home/dsnow/dsnow/NODE0000 graphics/ccc.gif /SQL00001/SQLOGDIR/ Overflow log path (OVERFLOWLOGPATH) = Mirror log path (MIRRORLOGPATH) = First active log file = Block log on disk full (BLK_LOG_DSK_FUL) = NO Percent of max active log space by transaction(MAX_LOG) = 0 Num. of active log files for 1 active UOW(NUM_LOG_SPAN) = 0 Group commit count (MINCOMMIT) = 1 Percent log file reclaimed before soft chckpt (SOFTMAX) = 100 Log retain for recovery enabled (LOGRETAIN) = OFF User exit for logging enabled (USEREXIT) = OFF Auto restart enabled (AUTORESTART) = ON Index re-creation time (INDEXREC) = SYSTEM (RESTART) Default number of loadrec sessions (DFT_LOADREC_SES) = 1 Number of database backups to retain (NUM_DB_BACKUPS) = 12 Recovery history retention (days) (REC_HIS_RETENTN) = 366 TSM management class (TSM_MGMTCLASS) = TSM node name (TSM_NODENAME) = TSM owner (TSM_OWNER) = TSM password (TSM_PASSWORD) =
Step 2: Adjust Relevant Parameters and Determine Values for the Task Being Optimized

The relevant database manager and database configuration parameters were adjusted, based on the analysis of their currently set values, and the appropriate values for the task being organized were determined. The configurations were updated as follows :

  update dbm cfg using intra_parallel on   update dbm cfg using sheapthres 60000   update db cfg for sample using logbufsz 256   update db cfg for sample using sortheap 1000  

The instance was stopped and restarted.

Step 3: Rerun the CREATE INDEX Statement

The db2batch output showing the timing of the create index is below. Although the create index time was improved, it was still higher than expected.

  ---------------------------------------------   Statement number: 1   create index x1 on staff (id)   Elapsed Time is:            897.214   seconds   ---------------------------------------------  
Step 4: Check the System for I/O Bottlenecks, Excess Paging, or Other Processes/Applications Using Excessive System Resources

This required operating system tools such as vmstat, iostat, and/or top to capture the memory, I/O, and process level information.

NOTE

It is important to capture the snapshots from these tools over a period of time, not taking just one snapshot, especially because the first line of the output of the vmstat and iostat tools contains average information since the server was started and is not really useful in analyzing a problem.


While the create index statement is running, capture vmstat output, as follows:

  vmstat 5 > vmstat.out  

This will capture a vmstat snapshot every 5 seconds and write the output to the file vmstat.out. This command will run until a Ctrl-C is issued on the terminal where the command was run. After this, examine the vmstat.out file.

Below is the vmstat.out file that was captured while the create index statement was running:

  kthr     memory             page              faults        cpu   ----- ----------- ------------------------ ------------ -----------   r  b   avm   fre  re  pi  po  fr   sr  cy  in   sy  cs us sy id wa   1  1 16243 29168   0   0   0   0    0   0 305 2890 870 14  6 80  0   2  1 16243 29165   0   0   0   0    0   0 212 2010 550 25  7 68  0   0  1 16243 29165   0   0   0   0    0   0 217 1175 584 24  2 74  0   0  1 16243 29165   0   0   0   0    0   0 224 1970 563 25  6 63  2   2  1 16243 29165   0   0   0   0    0   0 217 1171 583 23  2 75  0   2  1 16243 29165   0   0   0   0    0   0 211 1968 550 25  7 68  0   0  1 16243 29165   0   0   0   0    0   0 217 1175 584 24  1 75  0   2  1 16328 29072   0   0   0   0    0   0 217 1202 584 23  3 74  0  

The analysis of the vmstat output above did not indicate any problems. The run queue was small and did not grow over time. There was no paging occurring at any time during the run (as indicated by pi = 0). The CPUs were not waiting for I/O (as indicated by the wa column).

While the create index statement was running, the iostat information was captured, as follows:

  iostat 5 > iostat.out  

The iostat.out file was created as follows:

  Disks:        % tm_act     Kbps      tps    Kb_read   Kb_wrtn   Hdisk0          12.6      13.2       7.3         46         0   hdisk1           8.8       9.6       6.4         28         0   cd0              0.0       0.0       0.0          0         0   Disks:        % tm_act     Kbps      tps    Kb_read   Kb_wrtn   Hdisk0          10.6      11.3       6.9         37         0   hdisk1           9.8      10.9       6.8         33         0   cd0              0.0       0.0       0.0          0         0   Disks:        % tm_act     Kbps      tps    Kb_read   Kb_wrtn   Hdisk0          12.9      13.7       7.8         49         0   hdisk1           8.4       9.3       6.2         30         0   cd0              0.0       0.0       0.0          0         0  

The iostat showed that the disks were relatively inactive. The most active disk was busy only 12.9% of the time. In addition, the amount of data read (Kb_read) for the disks was quite low.

In this case each of the Hdisks was actually a disk array that could support much higher throughput. Disk arrays make the disk volume look like one disk to the OS tools; therefore, it was important to understand the physical disk implementation when examining the output of these tools.

In reexamining the database and database manager configurations, the NUM_IOSERVERS configuration parameter warranted further investigation. The parameter was set as follows:

  Number of I/O servers                   (NUM_IOSERVERS) = 1  

DB2 was not taking advantage of I/O parallelism and was not reading from the disks in parallel. In addition, because the containers were on a RAID-5 disk, we checked the DB2_PARALLEL_IO registry variable to determine whether it was set for the table space(s) where the table was created. In this, case it was not enabled.

The number of prefetchers (I/O servers) was increased as follows:

  update db cfg for sample using num_ioservers 6  

In this case, the number of prefetchers was set to six because the disk volume is using RAID-5 technology with six data disks and one parity disk per array. Therefore, there were six disks servicing the table space for the data.

Parallel I/O was enabled as follows:

  db2set DB2_PARALLEL_IO=*  

The DB2 instance was stopped and restarted to enable the registry variable.

Step 5: Rerun the CREATE INDEX Statement

The db2batch output showing the timing of the create index is below. Although the create index time was improved, it was still higher than expected.

  ---------------------------------------------   Statement number: 1   create index x1 on staff (id)   Elapsed Time is:            437.391   seconds   ---------------------------------------------  
Step 6: Recheck the System Resource Usage

In this case, two sessions were opened, and the vmstat and iostat were captured for the entire time the index was being created.

Some of the entries from the beginning and end of the vmstat.out and iostat.out files are below:

  kthr     memory             page              faults        cpu   ----- ----------- ------------------------ ------------ -----------   r  b   avm   fre  re  pi  po  fr   sr  cy  in   sy  cs us sy id wa   1  1 16243 29168   0   0   0   0    0   0 305 2890 870 14  6 80  0   2  1 16243 29165   0   0   0   0    0   0 212 2010 550 35  7 58  0   0  1 16243 29165   0   0   0   0    0   0 217 1175 584 34  2 64  0   0  1 16243 29165   0   0   0   0    0   0 224 1970 563 35  6 53  2   .   .   .   2  1 16243 29165   0   0   0   0    0   0 211 1968 550 25  7 61  7   0  1 16243 29165   0   0   0   0    0   0 217 1175 584 24  1 66  9   2  1 16328 29072   0   0   0   0    0   0 217 1202 584 23  3 67  7   Disks:        % tm_act     Kbps      tps    Kb_read   Kb_wrtn   Hdisk0          12.6      13.2       7.3         46         0   hdisk1           8.8       9.6       6.4         28         0   cd0              0.0       0.0       0.0          0         0   Disks:        % tm_act     Kbps      tps    Kb_read   Kb_wrtn   Hdisk0          10.6      11.3       6.9         37         0   hdisk1           9.8      10.9       6.8         33         0   cd0              0.0       0.0       0.0          0         0   Disks:        % tm_act     Kbps      tps    Kb_read   Kb_wrtn   Hdisk0          12.9      13.7       7.8         49         0   hdisk1           8.4       9.3       6.2         30         0   cd0              0.0       0.0       0.0          0         0   .   .   .   Disks:        % tm_act     Kbps      tps    Kb_read   Kb_wrtn   Hdisk0          24.7      36.1      16.3          1       317   Hdisk1          24.5      36.0      16.1          2       311   cd0              0.0       0.0       0.0          0         0   Disks:        % tm_act     Kbps      tps    Kb_read   Kb_wrtn   Hdisk0          24.6      36.1      16.3          1       315   Hdisk1          24.9      36.9      16.4          2       321   cd0              0.0       0.0       0.0          0         0   Disks:        % tm_act     Kbps      tps    Kb_read   Kb_wrtn   Hdisk0          24.5      36.0      16.2          1       315   Hdisk1          24.6      36.4      16.5          2       323   cd0              0.0       0.0       0.0          0         0  

An analysis of this information shows differences in the processing between the beginning and end of the create index processing. At the beginning of the processing, all of the I/O activity was shown to be reading the data file. At the end of the create index processing, all of the activity is write activity. This was due to the manner in which DB2 creates indexes.

Because DB2 logs only the creation of index pages and not the creation of every index key value, it must flush all of the new log pages to disk at the end of the index creation. With a CHNGPGS_THRESH setting of 60% and a 1.2-GB buffer pool, at the end of the index creation, there can be up to 720 MB of pages in the buffer pool that needs to be flushed to disk. By decreasing the value of the CHNGPGS_THRESH configuration parameter to 20%, there will be a maximum of only 240 MB of pages in the buffer pool to be flushed to disk. This can result in greatly improved index creation times.

Step 7: Adjust Relevant Parameters and Determine Values for the Task Being Optimized

The relevant database manager and database configuration parameters were adjusted, based on the analysis of their currently set values, and the appropriate values for the task being organized were determined. The changed pages threshold was updated as follows:

  update db cfg for sample using chngpgs_thresh 20  
Step 8: Rerun the CREATE INDEX Statement

The db2batch output showing the timing of the create index improved dramatically.

  ---------------------------------------------   Statement number: 1   create index x1 on staff (id)   Elapsed Time is:            38.451   seconds   ---------------------------------------------  


Advanced DBA Certification Guide and Reference for DB2 UDB v8 for Linux, Unix and Windows
Advanced DBA Certification Guide and Reference for DB2 Universal Database v8 for Linux, UNIX, and Windows
ISBN: 0130463884
EAN: 2147483647
Year: 2003
Pages: 121

flylib.com © 2008-2017.
If you may any questions please contact us: flylib@qtcs.net