[Progress Communities] [Progress OpenEdge ABL] Forum Post: How fast Progress utilities read the disks?

Status
Not open for further replies.
G

George Potemkin

Guest
The recent issue with viewB2 raised the question how fast Progress utilities read the disks. How many disk reads they can generate? Do they read the data volume we expect they should? The post is long. It’s a good idea to take beer before you will start reading. Test environment: Old Sparc server. SunOS 5.10. Slow CPU (1165 MHz). 32 GB RAM. A single HDD disk a database is resided on. I used the sports database blown up to 13 GB (with 3 GB of real data inside). Db blocksize 8K. OpenEdge 11.7.5. I’m not sure that all results will be the same on the modern hardware but I have only what I have. File system cache was dropped each time before a test: time umount /test where /test is a mount point of file system the database resides on. umount: /test busy real 0m7.993s user 0m0.003s sys 0m7.956s On Linux you can use: echo 3 > /proc/sys/vm/drop_caches The results are statistically consistent with each run. The next run is remarkably faster if the cache is NOT dropped. The execution time of Progress utilities was estimated by the timestamps of the messages in database log. Some utilities were run using the modified PROMSGS file to redirect the additional messages to the log file. The read rate is also verified by the iostat. The number of blocks read by the utilities was verified through promon when the utility was re-run online. The database area of the interest ("Customer/Order Area") was mapped to the alternate buffer pool. The utilities were run with minimal set of the options to make the disk reads to be dominant. Sequential disk reads Speed: 113.36 MB/sec = 1 base unit a.k.a. the “speed of light”, iostat: 115820 kps, 128 tps time dd if=sports_8.d1 of=/dev/null bs=8192 Time: 1m55.205s, Size: 13694533632 bytes = 12.75 GB Offline probkup to /dev/null Speed: 45.35 MB/sec = 0.40 base unit, iostat: 48511 kps, 54 tps time probkup sports /dev/null Time: 302.366 sec, Size: 1754885 8K blocks = 13.4 GB [2020/02/22@15:30:48.843+0300] P-21081 T-1 I BACKUP : (451) Probkup session begin for root on /dev/pts/1. 00:05:02.366 = 302.366 sec [2020/02/22@15:35:51.209+0300] P-21081 T-1 I BACKUP : (334) Probkup session end. Online probkup to /dev/null Speed: 40.81 MB/sec = 0.36 base unit, iostat: 41858 kps, 46 tps time probkup online sports /dev/null Time: 335.939 sec, Size: 1754885 8K blocks = 13.4 GB [2020/02/25@11:10:20.126+0300] P-25301 T-1 I BACKUP 5: (5461) Begin backup of Data file(s). 00:05:35.939 = 335.939 sec [2020/02/25@11:15:56.065+0300] P-25301 T-1 I BACKUP 5: (5462) End backup of Data file(s). [2020/02/25@11:15:56.069+0300] P-25301 T-1 I BACKUP 5: (13625) Wrote a total of 51890 backup blocks using 13.5 GBytes of media. Online probkup is 10% slower than offline probkup most likely due to the latches and the buffer locks. Note that CPUs on this server are slow. Hence the operations with data in shared memory are slow. “In-memory” probkup to /dev/null Speed: 71.58 MB/sec = 0.63 base unit, iostat: 0 kps, 0 tps proserve sports -B 2000000 proutil sports -C dbanalys time probkup online sports /dev/null Time: 191.547 sec, Size: 1754885 8K blocks = 13.4 GB Logical reads: 1754952 O/S reads: 0 So probkup spends only 37-43% of its time reading the disks. proutil sports -C dbscan Speed: 109.26 MB/sec = 0.96 base unit, iostat: 114353 kps, 126 tps proutil sports -C trunc time proutil sports -C dbscan Time: 125.485 sec, Size: 1754885 8K blocks = 13.4 GB [2020/02/25@19:32:50.714+0300] P-25923 T-1 I DBUTIL (451) Database Repair session begin for root on batch. 00:02:05.485 = 125.485 sec [2020/02/25@19:34:56.199+0300] P-25923 T-1 I DBUTIL (334) Database Repair session end. One of the fastest Progress utilities but it can be run only offline. Dbanalys, chanalys, ixanalys, tabanalys Their speed may significantly vary depending from the length of the chains in a database. All of them are scanning Free Cluster Chain: Dbanalys and chanalys do this during “FREE CLUSTER CHAIN ANALYSIS” phase. Ixanalys and tabanalys do this before AREA " Name":Num BLOCK ANALYSIS phase (note: it’s not the same as “AREA BLOCK ANALYSIS” phase). All of them read only two blocks in each data cluster on Free Cluster Chain: first block (with the transactionId and serialNumber fields in the extended block header) and last block (with the nextCluster and prevCluster fields in the block header). The information about every cluster on the chain is kept in memory to be used by the utilities during the final phase of the area scan. I guess they build something similar to the “Area Cluster Allocation Blocks” that were planned but are not yet implemented. The viewB2 utility also scans the Free Cluster Chain but it reads only one block from each cluster – the last one. It just counts (inefficiently) the blocks on the chain. Chanalys running on database with long Free Cluster Chain Speed: 20.53 MB/sec = 0.18 base unit, iostat: 115168 kps, 128 tps Note: Mismatch between Progress reads and O/S reads according iostat: 20.53 MB/sec vs 112.5 MB/sec! Iostat is as of the dd command. time proutil sports -C chanalys "Customer/Order Area" | tail Time: 115.936 sec, Size: 304680 8K blocks = 2.32 GB [2020/02/26@14:51:55.820+0300] P-26946 T-1 I CHANALYS6: (-----) FREE CLUSTER CHAIN ANALYSIS 00:01:55.936 = 115.936 sec [2020/02/26@14:53:51.756+0300] P-26946 T-1 I CHANALYS6: (-----) 152340 cluster(s) found in the free cluster chain. Alternate Buffer Pool ("Customer/Order Area"): Logical reads 3 O/S reads 304680 = 2 * 152340 - clusters found in the free cluster chain. Note: chanalys was forced to quit after it finished scanning the Free Cluster Chain. Primary Buffer Pool (“Schema Area”): Logical reads 1709 O/S reads 14 Note: all *analys utilities do not update the “Logical reads” while they scan the Free Cluster Chain but they update the “O/S reads”. But they update the “Logical reads” on the final phase of area scan. Together with unexplained high O/S reads this looks like a bug. viewB2 running on database with long Free Cluster Chain Speed: 10.57 MB/sec = 0.09 base unit, iostat: 10860 kps, 1358 tps Note: the high number of transfers per second! Note: viewB2 and chanalys spend the same time to read Free Cluster Chain but viewB2 reads twice less database blocks and generates 10.6 times less O/S reads. proutil sports -C viewB2 Time: 112.643 sec, Size: 152345 8K blocks = 1.16 GB [2020/02/26@14:08:44.226+0300] P-26874 T-1 I DBUTIL : (-----) Area "Info Area":7 - Primary Buffer Pool 00:01:52.643 = 112.643 sec [2020/02/26@14:10:36.869+0300] P-26874 T-1 I DBUTIL : (-----) Area "Customer/Order Area":8 - Alternate Buffer Pool Note: viewB2 reports statistics per area when it finishes reading the area. Alternate Buffer Pool ("Customer/Order Area"): Logical reads 152346 O/S reads 152345 (152340 - clusters found in the free cluster chain) Chanalys and /offline/ dbanalys also scan the object’s chains: Free Chain RM Chain Index Delete Chain Online dbanalys reports the same information about those chains like offline dbanalys does but it does not really scan them (unlike offline dbanalys). The sports database does not have the long object’s chains. Their read rate was not benchmarked in my tests. The final phase of these utilities is AREA "Area Name": AreaNum BLOCK ANALYSIS. The *analys utilities scan the whole area except the clusters on the Free Cluster Chain. If the chain is empty then the scan on this phase is sequential. The next results are for the areas that does not have long chains. Ixanalys running on the area without long Free Cluster Chain Speed: 86.84 MB/sec = 0.77 base unit time proutil sports -C ixanalys "Customer/Order Area" Time: 150.389 sec, Size: 1671695 8K blocks = 12.75 GBytes [2020/02/22@16:22:02.091+0300] P-21134 T-1 I IXANALYS : (451) Idxanalys session begin for root on /dev/pts/1. 00:02:30.389 = 150.389 sec [2020/02/22@16:24:32.480+0300] P-21134 T-1 I IXANALYS : (334) Idxanalys session end. Type of data stored in the area does not matter. You can run ixanalys against a table area. Utility will sequentially scan the area up to HWM (all active blocks). The fastest Progress utility that can be run per area. Tabanalys running on the area without long Free Cluster Chain Speed: 86.84 MB/sec = 0.77 base unit time proutil sports -C tabanalys "Customer/Order Area" Time: 150.389 sec, Size: 1671695 8K blocks = 12.75 GBytes Tabanlys can be a few times slower than ixanalys when it runs on an area where the records are fragmented. Otherwise the speed is the same as of ixanalys. Tip: compare the times of tabanalys and chanalys for the same table’s area to make a decision if you need a dump/load to defragment the records in the area. There are some interesting results for idxfix and idxcheck. I will post them later but right now the keyboard is tired.

Continue reading...
 
Status
Not open for further replies.
Top