VERY slow BTS index build

Hi All, First off, thank you all for your assistance so far in helping me get BTS blade setup. I am trying to build a BTS index across 950K rows defined as char(25). create index cp_lnm_bts_idx on char_person (cp_lname bts_char_ops) using bts We ran into issues with running out of Temp space (we expanded the SBSPACETEMP to 60GB and still ran into the issue) or running into Long Transactions. I found a blog writeup by Mark Ashworth ("Use of temporary sbspace in BTS" 12/2010) (http://webcache.googleusercontent.com/search?q=cache:FDYPM8cCceQJ:https://www.i bm.com/developerworks/community/blogs/markashworth/entry/use_of_temporary_snspac e_in_bts1+&cd=1&hl=en&ct=clnk&gl=us) Once I recreated the bts_temp space as a temporary sbspace, the build completed, but it took **over 20 HOURS**!!! I bounced the engine after adding more BTS VPs (1 -> 3), Buffers (50K -> 400K), and splitting the SB temp into 3 separate 20GB spaces. The index build is running again, however it seems to be dragging along. So far, running for 6 hours. The buffers seem to be adding/modifying very slowly, so I'm expecting this rebuild to be no faster than the previous. One immediate issue: setting SBSPACETEMP to bts_temp:bts_temp1:bts_temp2 causes a warning when the index build begins ("space not found"). Is ":" not the appropriate delimiter? It's what we use for DBSPACETEMP. I tried ',', but that didn't work either -- no error, but all work was logged in the default sbspace. I had to reset SBSPACETEMP to only bts_temp, and the system seems to be working with only that temp space. :-( Here are some snapshots: (a couple of the snapshots were run twice after 10 or 15 seconds to show changes) (relevant settings from onstat -c at end) Last Name (SQL OUTPUT) ========================== start-time 2014-09-05 10:37:08.000 date: Fri Sep 5 15:26:10 MDT 2014 onstat -g ses 27 ------------------ IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:58:08 --1278976 Kbytes session effective #RSAM total used dynamic id user user tty pid hostname threads memory memory explain 27 devdba - 1 3406 devdata2 1 700416 568784 off tid name rstcb flags curstk status 57 sqlexec 145366e00 --BP--- 23550 running- Memory pools count 2 name class addr totalsize freesize #allocfrag #freefrag 27 V 1463c2040 696320 130824 638 132 27*O0 V 146410040 4096 808 1 1 name free used name free used overhead 0 6576 mtmisc 0 72 scb 0 144 opentable 0 11832 filetable 0 2192 log 0 16536 temprec 0 21664 partn 0 72 keys 0 1192 ralloc 0 441448 gentcb 0 1584 ostcb 0 2816 sqscb 0 24040 sql 0 72 rdahead 0 1120 hashfiletab 0 552 osenv 0 3504 sqtcb 0 10952 fragman 0 11640 GenPg 0 872 sapi 0 200 SAPI callback 0 720 udr 0 872 sqlj 0 72 vii 0 7736 sqscb info scb sqscb optofc pdqpriority optcompind directives 1463b90c0 1463c3028 0 100 0 1 Sess SQL Current Iso Lock SQL ISAM F.E. Id Stmt type Database Lvl Mode ERR ERR Vers Explain 27 CREATE INDEX char CR Not Wait 0 0 9.24 Off Current SQL statement : create index cp_lnm_bts_idx on char_person (cp_lname bts_char_ops) using bts onstat -d ------------------ IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:50:03 -- 1278976 Kbytes Dbspaces address number flags fchunk nchunks pgsize flags owner name 14603ae28 4 0x1 7 1 2048 N informi x chardb 1461b61c0 26 0x68001 61 2 2048 N SB informi x bts_sbpace 1461b6358 27 0x4a001 62 1 2048 N UB informi x bts_temp 1461b64f0 28 0x4a001 63 1 2048 N UB informi x bts_temp1 1461b6688 29 0x4a001 65 1 2048 N UB informi x bts_temp2 Chunks address chunk/dbs offset size free bpages flags pathname 1461b7218 7 4 50 1000000 362208 PO--- /dev/md/rdsk/d114 1461bddb8 61 26 0 10000000 7993025 7999947 POSB- /dev/md/rdsk/d136 Metadata 2000000 1680069 2000000 1461bf028 62 27 0 10000000 9306697 9326885 POSB- /dev/md/rdsk/d137 Metadata 673062 500842 673062 1461bf218 63 28 0 10000000 9326885 9326885 POSB- /dev/md/rdsk/d138 Metadata 673062 500842 673062 1461bf408 64 26 0 10000000 9264826 9326931 POSB- /dev/md/rdsk/d135 Metadata 673066 673066 673066 1461bf5f8 65 29 0 10000000 9326885 9326885 POSB- /dev/md/rdsk/d133 Metadata 673062 500842 673062 onstat -D ------------- IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:52:07 -- 1278976 Kbytes Dbspaces address number flags fchunk nchunks pgsize flags owner name 14603ae28 4 0x1 7 1 2048 N informi x chardb 1461b61c0 26 0x68001 61 2 2048 N SB informi x bts_sbpace 1461b6358 27 0x4a001 62 1 2048 N UB informi x bts_temp 1461b64f0 28 0x4a001 63 1 2048 N UB informi x bts_temp1 1461b6688 29 0x4a001 65 1 2048 N UB informi x bts_temp2 Chunks address chunk/dbs offset page Rd page Wr pathname 1461b7218 7 4 50 223876 4 /dev/md/rdsk/d114 1461bddb8 61 26 0 65535 7 /dev/md/rdsk/d136 1461bf028 62 27 0 51 52472 /dev/md/rdsk/d137 1461bf218 63 28 0 51 60 /dev/md/rdsk/d138 1461bf408 64 26 0 1 0 /dev/md/rdsk/d135 1461bf5f8 65 29 0 51 60 /dev/md/rdsk/d133 IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 05:04:42 --1278976 Kbytes 1461b7218 7 4 50 227782 4 /dev/md/rdsk/d114 1461bddb8 61 26 0 65535 7 /dev/md/rdsk/d136 1461bf028 62 27 0 51 52472 /dev/md/rdsk/d137 1461bf218 63 28 0 51 60 /dev/md/rdsk/d138 1461bf408 64 26 0 1 0 /dev/md/rdsk/d135 1461bf5f8 65 29 0 51 60 /dev/md/rdsk/d133 onstat -b ------------------- IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:54:13 --1278976 Kbytes Buffers address userthread flgs pagenum memaddr nslots pgflgs xflgs owner waitlist Buffer pool page size: 2048 1138817e8 0 80807 62:4734256 1407e0000 2 81 0 0 0 45977 modified, 400000 total, 524288 hash buckets, 2048 buffer size IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 05:03:53 --1278976 Kbytes Buffers address userthread flgs pagenum memaddr nslots pgflgs xflgs owner waitlist Buffer pool page size: 2048 47677 modified, 400000 total, 524288 hash buckets, 2048 buffer size onstat -P ------------ IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:54:42 --1278976 Kbytes Buffer pool page size: 2048 partnum total btree data other dirty 0 63965 0 29609 34356 29584 1048577 77 0 75 2 8 [snip] 27262981 53176 0 53162 14 0 27262982 1 0 1 0 0 27262983 12326 0 12322 4 0 28311553 6 0 5 1 0 28311554 2 0 1 1 1 28311555 2 0 1 1 0 28311556 20 0 13 7 14 28311557 44947 0 44910 37 16402 [snip] Totals: 400000 309 365077 34614 46071 Percentages: Data 91.27 Btree 0.08 Other 8.65 onstat -p ----------- IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:55:33 --1278976 Kbytes Profile dskreads pagreads bufreads %cached dskwrits pagwrits bufwrits %cached 291374 291467 412247733 99.93 52849 53094 173829735 99.97 isamtot open start read write rewrite delete commit rollbk 560480642 1616994

> On 05 September 2014 at 23:13 MICHAEL HOFFMAN <mrh@panix.com> wrote: > > > Hi All, > First off, thank you all for your assistance so far in helping me get BTS > blade setup. > > I am trying to build a BTS index across 950K rows defined as char(25). > > create index cp_lnm_bts_idx on char_person (cp_lname bts_char_ops) using> > bts > > We ran into issues with running out of Temp space (we expanded the SBSPACETEMP> to 60GB and still ran into the issue) or running into Long Transactions. > > I found a blog writeup by Mark Ashworth ("Use of temporary sbspace in BTS" > 12/2010) > > (http://webcache.googleusercontent.com/search?q=cache:FDYPM8cCceQJ:https://www.i bm.com/developerworks/community/blogs/markashworth/entry/use_of_temporary_snspac e_in_bts1+&cd=1&hl=en&ct=clnk&gl=us) > > Once I recreated the bts_temp space as a temporary sbspace, the build > completed, but it took **over 20 HOURS**!!! > > I bounced the engine after adding more BTS VPs (1 -> 3), Buffers (50K -> > 400K), and splitting the SB temp into 3 separate 20GB spaces. > > The index build is running again, however it seems to be dragging along. So > far, running for 6 hours. The buffers seem to be adding/modifying very slowly, > so I'm expecting this rebuild to be no faster than the previous. > > One immediate issue: setting SBSPACETEMP to bts_temp:bts_temp1:bts_temp2 > causes a warning when the index build begins ("space not found"). Is ":" not > the appropriate delimiter? It's what we use for DBSPACETEMP. I tried ',', but > that didn't work either -- no error, but all work was logged in the default > sbspace. > > I had to reset SBSPACETEMP to only bts_temp, and the system seems to be > working with only that temp space. :-( > In 11.50 http://www-01.ibm.com/support/knowledgecenter/SSGU8G_11.50.0/com.ibm.adref.doc/i ds_adr_0148.htm mentions "SBSPACETEMP specifies THE name of the default temporary sbspace for storing temporary smart large objects without metadata or user-data logging." Use of "THE name" implies 1 space only! In 11.70 http://www-01.ibm.com/support/knowledgecenter/SSGU8G_11.70.0/com.ibm.adref.doc/i ds_adr_0148.htm "values One or more sbspace names. Separate names with a comma. The length of the list cannot exceed 128 bytes." NOTE: Also 11.70 adds http://www-01.ibm.com/support/knowledgecenter/api/content/SSGU8G_11.70.0/com.ibm .po.doc/new_features.htm?locale=en&ro=kcUI#xc8__xc8_bts "You can build the bts index faster in RAM than in a temporary sbspace by including the xact_ramdirectory="yes" index parameter." Which OS is this running on and what hardware? Regards, David.

Thanks David! I missed that line! In the onconfig file it describes SBSPACETEMP as: # SBSPACETEMP - The list of sbspaces used to store temporary # tables for smart large objects. If no sbspace # is specified, temporary files are created in # a standard sbspace. And we wonder why DBAs get confused! LOL! This is running on a Solaris 10 system. Thanks, Michael

Hi Michael, I believe SBSPACETEMP is a list of sbspaces. I am know that BTS will accept a list of sbspaces, but it only uses one of the spaces listed, as documented in BTS: A temporary sbspace that is specified by the SBSPACETEMP configuration parameter. The temporary sbspace with the most free space is used. If no temporary sbspaces are listed, the sbspace with the most free space is used. -- Mark. Mark Ashworth IBM Informix Extensibility Architect Office phone: +1 (905) 413-5033 Alternate: +1 (905) 697-8094 Email: ashworth@ca.ibm.com Check out my blog From: "MICHAEL HOFFMAN" <mrh@panix.com> To: ids@iiug.org, Date: 09/05/2014 08:41 PM Subject: Re: VERY slow BTS index build [33718] Sent by: ids-bounces@iiug.org Thanks David! I missed that line! In the onconfig file it describes SBSPACETEMP as: # SBSPACETEMP - The list of sbspaces used to store temporary # tables for smart large objects. If no sbspace # is specified, temporary files are created in # a standard sbspace. And we wonder why DBAs get confused! LOL! This is running on a Solaris 10 system. Thanks, Michael ******************************************************************************* Forum Note: Use "Reply" to post a response in the discussion forum.

HI Michael, > One immediate issue: setting SBSPACETEMP to bts_temp:bts_temp1:bts_temp2 > causes a warning when the index build begins ("space not found"). Is ":" not > the appropriate delimiter? It's what we use for DBSPACETEMP. I tried ',', but > that didn't work either -- no error, but all work was logged in the default > sbspace. I had a look back at 11.50.xC6 and in that veraion BTS did not support a list of sbpaces in SBSPACETEMP. This was a fix applied to 11.50.xC7. In 11.50.xC7 and beyond, it will support a comma or colon separated list of sbspaces. 11.50.xC7 also has online log warnings when it fines that an sbspace listed in SBSPACETEMP is not a valid sbspace or not a tempsbspace. -- Mark. Mark Ashworth IBM Informix Extensibility Architect Office phone: +1 (905) 413-5033 Alternate: +1 (905) 697-8094 Email: ashworth@ca.ibm.com Check out my blog From: "MICHAEL HOFFMAN" <mrh@panix.com> To: ids@iiug.org, Date: 09/05/2014 06:14 PM Subject: VERY slow BTS index build [33714] Sent by: ids-bounces@iiug.org Hi All, First off, thank you all for your assistance so far in helping me get BTS blade setup. I am trying to build a BTS index across 950K rows defined as char(25). create index cp_lnm_bts_idx on char_person (cp_lname bts_char_ops) using bts We ran into issues with running out of Temp space (we expanded the SBSPACETEMPto 60GB and still ran into the issue) or running into Long Transactions. I found a blog writeup by Mark Ashworth ("Use of temporary sbspace in BTS" 12/2010) ( http://webcache.googleusercontent.com/search?q=cache:FDYPM8cCceQJ:https://www.ib m.com/developerworks/community/blogs/markashworth/entry/use_of_temporary_snspace _in_bts1+&cd=1&hl=en&ct=clnk&gl=us ) Once I recreated the bts_temp space as a temporary sbspace, the build completed, but it took **over 20 HOURS**!!! I bounced the engine after adding more BTS VPs (1 -> 3), Buffers (50K -> 400K), and splitting the SB temp into 3 separate 20GB spaces. The index build is running again, however it seems to be dragging along. So far, running for 6 hours. The buffers seem to be adding/modifying very slowly, so I'm expecting this rebuild to be no faster than the previous. One immediate issue: setting SBSPACETEMP to bts_temp:bts_temp1:bts_temp2 causes a warning when the index build begins ("space not found"). Is ":" not the appropriate delimiter? It's what we use for DBSPACETEMP. I tried ',', but that didn't work either -- no error, but all work was logged in the default sbspace. I had to reset SBSPACETEMP to only bts_temp, and the system seems to be working with only that temp space. :-( Here are some snapshots: (a couple of the snapshots were run twice after 10 or 15 seconds to show changes) (relevant settings from onstat -c at end) Last Name (SQL OUTPUT) ========================== start-time 2014-09-05 10:37:08.000 date: Fri Sep 5 15:26:10 MDT 2014 onstat -g ses 27 ------------------ IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:58:08 -- 1278976 Kbytes session effective #RSAM total used dynamic id user user tty pid hostname threads memory memory explain 27 devdba - 1 3406 devdata2 1 700416 568784 off tid name rstcb flags curstk status 57 sqlexec 145366e00 --BP--- 23550 running- Memory pools count 2 name class addr totalsize freesize #allocfrag #freefrag 27 V 1463c2040 696320 130824 638 132 27*O0 V 146410040 4096 808 1 1 name free used name free used overhead 0 6576 mtmisc 0 72 scb 0 144 opentable 0 11832 filetable 0 2192 log 0 16536 temprec 0 21664 partn 0 72 keys 0 1192 ralloc 0 441448 gentcb 0 1584 ostcb 0 2816 sqscb 0 24040 sql 0 72 rdahead 0 1120 hashfiletab 0 552 osenv 0 3504 sqtcb 0 10952 fragman 0 11640 GenPg 0 872 sapi 0 200 SAPI callback 0 720 udr 0 872 sqlj 0 72 vii 0 7736 sqscb info scb sqscb optofc pdqpriority optcompind directives 1463b90c0 1463c3028 0 100 0 1 Sess SQL Current Iso Lock SQL ISAM F.E. Id Stmt type Database Lvl Mode ERR ERR Vers Explain 27 CREATE INDEX char CR Not Wait 0 0 9.24 Off Current SQL statement : create index cp_lnm_bts_idx on char_person (cp_lname bts_char_ops) using bts onstat -d ------------------ IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:50:03 --1 278976 Kbytes Dbspaces address number flags fchunk nchunks pgsize flags owner name 14603ae28 4 0x1 7 1 2048 N informi x chardb 1461b61c0 26 0x68001 61 2 2048 N SB informi x bts_sbpace 1461b6358 27 0x4a001 62 1 2048 N UB informi x bts_temp 1461b64f0 28 0x4a001 63 1 2048 N UB informi x bts_temp1 1461b6688 29 0x4a001 65 1 2048 N UB informi x bts_temp2 Chunks address chunk/dbs offset size free bpages flags pathname 1461b7218 7 4 50 1000000 362208 PO--- /dev/md/rdsk/d114 1461bddb8 61 26 0 10000000 7993025 7999947 POSB- /dev/md/rdsk/d136 Metadata 2000000 1680069 2000000 1461bf028 62 27 0 10000000 9306697 9326885 POSB- /dev/md/rdsk/d137 Metadata 673062 500842 673062 1461bf218 63 28 0 10000000 9326885 9326885 POSB- /dev/md/rdsk/d138 Metadata 673062 500842 673062 1461bf408 64 26 0 10000000 9264826 9326931 POSB- /dev/md/rdsk/d135 Metadata 673066 673066 673066 1461bf5f8 65 29 0 10000000 9326885 9326885 POSB- /dev/md/rdsk/d133 Metadata 673062 500842 673062 onstat -D ------------- IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:52:07 --1 278976 Kbytes Dbspaces address number flags fchunk nchunks pgsize flags owner name 14603ae28 4 0x1 7 1 2048 N informi x chardb 1461b61c0 26 0x68001 61 2 2048 N SB informi x bts_sbpace 1461b6358 27 0x4a001 62 1 2048 N UB informi x bts_temp 1461b64f0 28 0x4a001 63 1 2048 N UB informi x bts_temp1 1461b6688 29 0x4a001 65 1 2048 N UB informi x bts_temp2 Chunks address chunk/dbs offset page Rd page Wr pathname 1461b7218 7 4 50 223876 4 /dev/md/rdsk/d114 1461bddb8 61 26 0 65535 7 /dev/md/rdsk/d136 1461bf028 62 27 0 51 52472 /dev/md/rdsk/d137 1461bf218 63 28 0 51 60 /dev/md/rdsk/d138 1461bf408 64 26 0 1 0 /dev/md/rdsk/d135 1461bf5f8 65 29 0 51 60 /dev/md/rdsk/d133 IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 05:04:42 -- 1278976 Kbytes 1461b7218 7 4 50 227782 4 /dev/md/rdsk/d114 1461bddb8 61 26 0 65535 7 /dev/md/rdsk/d136 1461bf028 62 27 0 51 52472 /dev/md/rdsk/d137 1461bf218 63 28 0 51 60 /dev/md/rdsk/d138 1461bf408 64 26 0 1 0 /dev/md/rdsk/d135 1461bf5f8 65 29 0 51 60 /dev/md/rdsk/d133 onstat -b ------------------- IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:54:13 -- 1278976 Kbytes Buffers address userthread flgs pagenum memaddr nslots pgflgs xflgs owner waitlist Buffer pool page size: 2048 1138817e8 0 80807 62:4734256 1407e0000 2 81 0 0 0 45977 modified, 400000 total, 524288 hash buckets, 2048 buffer size IBM Informix Dynami

>> I had a look back at 11.50.xC6 and in that veraion BTS did not support a >> list of sbpaces in SBSPACETEMP. This was a fix applied to 11.50.xC7. >> In 11.50.xC7 and beyond, it will support a comma or colon separated list >> of sbspaces. 11.50.xC7 also has online log warnings when it fines >> that an sbspace listed in SBSPACETEMP is not a valid sbspace or not a >> tempsbspace. Thanks Mark. That follows what I saw happening during the index build. I was hoping that parallel sorting would cocur in multiple tables across the temp sbspaces, but alas, no. Well, I don't think that is the crux of the slowness issue anyway. But good to have one question resolved. :-) Michael

Final outcom of the build: **25 hours***!! There has GOT to be a way to speed this up, right? Checkpoints throughout the process ran in 2 seconds or less. Overall buffer usage was 96% Data, 3.5% Other. So the estimate of 400000 Buffers was pretty accurate. Any ideas what I should look to chance to make this index build run quicker? There is no way we'll be able to implement BTS if that is the performance we should expect. :-( Thanks, Michael

Hi Michael, BTS is a little sensitive in performance to the vocabulary of the data being indexed (ie how many distinct words). With a 300,000 word vocabulary, I just tried an index build with 950,000 rows with a char(25) column (containing 1 -4 random words from the vocabulary) on an idle linux x86-64 VM with 11.50.FC8W4 with a demo server created by the install (ie basically a default onconfig file) with on SBSBSPACE setup, one bts vp and SBSPACETEMP set to bts_temp with no other special BTS options on the create index statement. It took just over 7 minutes. onspaces -c -S bts_temp -t -o 0 -s 400000 -p $DIR/bts_temp select count(*) from bts_tab; (count(*)) 950000 IBM Informix Dynamic Server Version 11.50.FC8W4 -- On-Line -- Up 00:18:30 -- 64316 Kbytes create index bts_idx on bts_tab (text bts_char_ops) using bts inbts_index; Index created. real 7m2.699s onstat -l has 7 logs of size 5000 and 30 logs of size 10000. There were several BTS performance related defects addressed in fixpacks after 11.50.xC6. -- Mark. Mark Ashworth IBM Informix Extensibility Architect Office phone: +1 (905) 413-5033 Alternate: +1 (905) 697-8094 Email: ashworth@ca.ibm.com Check out my blog From: "MICHAEL HOFFMAN" <mrh@panix.com> To: ids@iiug.org, Date: 09/08/2014 12:46 PM Subject: Re: VERY slow BTS index build [33732] Sent by: ids-bounces@iiug.org Final outcom of the build: **25 hours***!! There has GOT to be a way to speed this up, right? Checkpoints throughout the process ran in 2 seconds or less. Overall buffer usage was 96% Data, 3.5% Other. So the estimate of 400000 Buffers was pretty accurate. Any ideas what I should look to chance to make this index build run quicker? There is no way we'll be able to implement BTS if that is the performance we should expect. :-( Thanks, Michael ******************************************************************************* Forum Note: Use "Reply" to post a response in the discussion forum.

Mark, That is the kind of response times I expect from Informix. I have no idea why these builds are taking so long. It seems as if varchar works faster than char, but they take a few hours as well. This system is a fairly idle server, used for QA mostly. When the BTS build is running, 'top' shows the Informix oninits sitting above all else, and the 'top' session next in line -- ie: nothing else is happening. I just ran a new test on a different column: char(25) with only *4* values for 980K rows. 850K are the same value. This should be a fairly simple index to create ... after all, a regular index on the column completes in about 3 minutes. After an hour-and-a-half, I stopped the test. No reason to wait any longer, that's just too slow. I dropped the Buffers down to 200000 and LRUs at 8. Pushed the SHMVRTSIZE to 2048000 -- the entire database should fit into that! SHMADD = 256000. EXTSHMADD = 4096. Looking at onstat -p, both Buffer Rates are above 99%. Good! Looking at onstat -p, both Buffer Rates are above 99%. Good! Looking at onstat -D shows some writes to bts_temp space (created the same way you did, with the '-t' option) and about 108000 reads from the databases dbspace. onstat -g opn shows several temp tables being opened and closed constantly. Hmm... after an 1.5 hours, it only did 108K reads? BTS must be sorting each row as it builds the index? Oh, and here's a CRAZY issue: immediately upon starting the build, the engine dynamically adds *4* "new extension shared memory" segments! By the time I had stopped the build, *8 segnemts* had been added. This boosted the virtual memory to 2077696. Why would the engine need more VM? As I said, with the boost of SHMVRTSIZE to 2GB, the entire database can fit there. Strange, huh? Art, you got any ideas? Thanks again! Really hoping to find an answer so I can convince the Big Boys to sign off on using BTS. Michael

Don't remember the thread details. What version? What OS? What is VP_MEMORY_CACHE_KB set to? Are you using PDQPRIORITY AND PSORT_NPROCS during the build? Art Art On Sep 8, 2014 6:45 PM, "MICHAEL HOFFMAN" <mrh@panix.com> wrote: > Mark, > That is the kind of response times I expect from Informix. > I have no idea why these builds are taking so long. It seems as if varchar > works faster than char, but they take a few hours as well. > > This system is a fairly idle server, used for QA mostly. When the BTS > build is > running, 'top' shows the Informix oninits sitting above all else, and the > 'top' session next in line -- ie: nothing else is happening. > > I just ran a new test on a different column: char(25) with only *4* values > for > 980K rows. 850K are the same value. This should be a fairly simple index to > create ... after all, a regular index on the column completes in about 3 > minutes. > After an hour-and-a-half, I stopped the test. No reason to wait any longer, > that's just too slow. > > I dropped the Buffers down to 200000 and LRUs at 8. Pushed the SHMVRTSIZE > to > 2048000 -- the entire database should fit into that! SHMADD = 256000. > EXTSHMADD = 4096.> > Looking at onstat -p, both Buffer Rates are above 99%. Good! > Looking at onstat -p, both Buffer Rates are above 99%. Good! > Looking at onstat -D shows some writes to bts_temp space (created the same > way > you did, with the '-t' option) and about 108000 reads from the databases > dbspace. > onstat -g opn shows several temp tables being opened and closed constantly.> > Hmm... after an 1.5 hours, it only did 108K reads? BTS must be sorting each > row as it builds the index? > > Oh, and here's a CRAZY issue: immediately upon starting the build, the > engine > dynamically adds *4* "new extension shared memory" segments! By the time I > had > stopped the build, *8 segnemts* had been added. This boosted the virtual > memory to 2077696. > Why would the engine need more VM? As I said, with the boost of SHMVRTSIZE > to > 2GB, the entire database can fit there. > > Strange, huh? Art, you got any ideas? > > Thanks again! Really hoping to find an answer so I can convince the Big > Boys > to sign off on using BTS. > > Michael > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --089e013d1c4605935f0502967429

>> Don't remember the thread details. What version? What OS? What is >> VP_MEMORY_CACHE_KB set to? Are you using PDQPRIORITY AND PSORT_NPROCS >> during the build? >> Art Hi Art, Informix 11.5.FC6 running on a Sun Solaris 10 system. PDQ set to 100. PSORT_NPROCS = 8. VP_MEMORY_CACHE_KB is disabled (set to 0). Thanks, Mike

>> Don't remember the thread details. What version? What OS? What is >> VP_MEMORY_CACHE_KB set to? Are you using PDQPRIORITY AND PSORT_NPROCS >> during the build? >> Art Hi Art, Informix 11.5.FC6 running on a Sun Solaris 10 system. PDQ set to 100. PSORT_NPROCS = 8. VP_MEMORY_CACHE_KB is disabled (set to 0). The really nutty thing about the extra memory segments (still running, and now over 25 added!) is that they aren't even being used. Here is a snippet of the onsat -g seg: IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 03:58:09 --2917376 Kbytes Segment Summary: id key addr size ovhd class blkused blkfree 68 525a4801 10a000000 596639744 7425232 R 145548 116 69 525a4802 12d900000 2097152000 24577792 V 13214 498786 70 525a4803 1aa900000 1048576 13552 M 159 97 71 525a4804 1aaa00000 4194304 50512 VX 1000 24 72 525a4805 1aae00000 4194304 50512 VX 986 38 [snip many VX] 125 525a483a 1b8700000 4194304 50512 VX 22 1002 126 525a483b 1b8b00000 4194304 50512 VX 21 1003 127 525a483c 1b8f00000 4194304 50512 VX 22 1002 16777216 525a483d 1b9300000 4194304 50512 VX 21 1003 16777217 525a483e 1b9700000 4194304 50512 VX 22 1002 16777221 525a483f 1b9b00000 4194304 50512 VX 21 1003 16777222 525a4840 1b9f00000 4194304 50512 VX 22 1002 16777223 525a4841 1ba300000 4194304 50512 VX 21 1003 Thanks, Mike

One thing to note, adding shared memory segments on Solaris is expensive and slow, so it is important to set SHMVIRTSIZE big enough so you don't have to add segments during the BTS index builds. Other than that, I don't have anything. I was thinking that you were hitting the problem with VP_MEMORY_CACHE_KB's semantics silently having been changed from STATIC to DYNAMIC in the early 11.70 releases, but 11.50 is safe from that one. Anyway the additional segments are slowing you down a little, not the big hit though. Art Art S. Kagel, Principal Consultant ASK Database Management Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Mon, Sep 8, 2014 at 10:26 PM, MICHAEL HOFFMAN <mrh@panix.com> wrote: > >> Don't remember the thread details. What version? What OS? What is > >> VP_MEMORY_CACHE_KB set to? Are you using PDQPRIORITY AND PSORT_NPROCS > >> during the build? > >> Art > > Hi Art, > Informix 11.5.FC6 running on a Sun Solaris 10 system. > PDQ set to 100. PSORT_NPROCS = 8. > VP_MEMORY_CACHE_KB is disabled (set to 0).> > Thanks, > Mike > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001a11340428b2062a05029f2b99

Very odd, because that does sound EXACTLY like the symptoms of the dynamic VP_MEMORY_CACHE_KB change in 11.70 from STATIC always to DYNAMIC always in the early releases to DYNAMIC by default with STATIC as an option in the later 11.70 & 12.10 releases. Since you are on 11.50 I wouldn't think that this is the problem, but it can't hurt to bring it up to your PMR contact. Again, adding shared memory segments under Solaris is VERY expensive and VERY slow, so with 25+ new segments, that may actually be a bigger part of the slowdown than I initially thought. Art Art S. Kagel, Principal Consultant ASK Database Management Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Mon, Sep 8, 2014 at 10:36 PM, MICHAEL HOFFMAN <mrh@panix.com> wrote: > >> Don't remember the thread details. What version? What OS? What is > >> VP_MEMORY_CACHE_KB set to? Are you using PDQPRIORITY AND PSORT_NPROCS > >> during the build? > >> Art > > Hi Art, > Informix 11.5.FC6 running on a Sun Solaris 10 system. > PDQ set to 100. PSORT_NPROCS = 8. > VP_MEMORY_CACHE_KB is disabled (set to 0).> > The really nutty thing about the extra memory segments (still running, and > now > over 25 added!) is that they aren't even being used. Here is a snippet of > the > onsat -g seg: > IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 03:58:09 --> 2917376 Kbytes > > Segment Summary: > id key addr size ovhd class blkused blkfree > 68 525a4801 10a000000 596639744 7425232 R 145548 116 > 69 525a4802 12d900000 2097152000 24577792 V 13214 498786 > 70 525a4803 1aa900000 1048576 13552 M 159 97 > 71 525a4804 1aaa00000 4194304 50512 VX 1000 24 > 72 525a4805 1aae00000 4194304 50512 VX 986 38 > [snip many VX] > 125 525a483a 1b8700000 4194304 50512 VX 22 1002 > 126 525a483b 1b8b00000 4194304 50512 VX 21 1003 > 127 525a483c 1b8f00000 4194304 50512 VX 22 1002 > 16777216 525a483d 1b9300000 4194304 50512 VX 21 1003 > 16777217 525a483e 1b9700000 4194304 50512 VX 22 1002 > 16777221 525a483f 1b9b00000 4194304 50512 VX 21 1003 > 16777222 525a4840 1b9f00000 4194304 50512 VX 22 1002 > 16777223 525a4841 1ba300000 4194304 50512 VX 21 1003 > > Thanks, > Mike > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --089e0160a3be1077ca05029f3860

Try setting this: MULTI_INDEX_SCAN 0 It created a memory leak in earlier versions of 11.70. Maybe that is what you are hitting. Thanks, Kate On Sep 8, 2014, at 10:36 PM, "MICHAEL HOFFMAN" <mrh@panix.com> wrote: >>> Don't remember the thread details. What version? What OS? What is >>> VP_MEMORY_CACHE_KB set to? Are you using PDQPRIORITY AND PSORT_NPROCS >>> during the build? >>> Art > > Hi Art, > Informix 11.5.FC6 running on a Sun Solaris 10 system. > PDQ set to 100. PSORT_NPROCS = 8. > VP_MEMORY_CACHE_KB is disabled (set to 0).> > The really nutty thing about the extra memory segments (still running, and now > over 25 added!) is that they aren't even being used. Here is a snippet of the > onsat -g seg: > IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 03:58:09 --> 2917376 Kbytes > > Segment Summary: > id key addr size ovhd class blkused blkfree > 68 525a4801 10a000000 596639744 7425232 R 145548 116 > 69 525a4802 12d900000 2097152000 24577792 V 13214 498786 > 70 525a4803 1aa900000 1048576 13552 M 159 97 > 71 525a4804 1aaa00000 4194304 50512 VX 1000 24 > 72 525a4805 1aae00000 4194304 50512 VX 986 38 > [snip many VX] > 125 525a483a 1b8700000 4194304 50512 VX 22 1002 > 126 525a483b 1b8b00000 4194304 50512 VX 21 1003 > 127 525a483c 1b8f00000 4194304 50512 VX 22 1002 > 16777216 525a483d 1b9300000 4194304 50512 VX 21 1003 > 16777217 525a483e 1b9700000 4194304 50512 VX 22 1002 > 16777221 525a483f 1b9b00000 4194304 50512 VX 21 1003 > 16777222 525a4840 1b9f00000 4194304 50512 VX 22 1002 > 16777223 525a4841 1ba300000 4194304 50512 VX 21 1003 > > Thanks, > Mike > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. >

Hi Michael, > It seems as if varchar > works faster than char, but they take a few hours as well. This is an interesting observation BTS will get trailing space characters with CHAR that are stripped early in the index pipeline. Other than that, from BTS, there should be no difference. > Oh, and here's a CRAZY issue: immediately upon starting the build, the engine > dynamically adds *4* "new extension shared memory" segments! By the > time I had > stopped the build, *8 segnemts* had been added. This boosted the virtual > memory to 2077696. > Why would the engine need more VM? As I said, with the boost of SHMVRTSIZE to > 2GB, the entire database can fit there. When BTS creates and index or inserts into an index, rows are inserted into the index stages. The first stage is an small in-memory structure called a ramdirectory. I typically run with EXTSHMADD set to 8192 and it governs the number the size of the VX class of memory segments. VX memory segments are associated with VPs like the bts VP. I have gone to 11.50.xC6 and trying the index build again. I do not see a memory leak where the VX segments are growing: IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 00:47:47 -- 72504 Kbytes Segment Summary: id key addr size ovhd class blkused blkfree 19922948 52564801 44000000 7249920 517984 R 1768 2 19955717 52564802 446ea000 33439744 393376 V 7792 372 19988486 52564803 466ce000 8388608 99712 V 155 1893 20021255 52564804 46ece000 8388608 99712 VX 576 1472 20054024 52564805 476ce000 8388608 99712 VX 349 1699 20086793 52564806 47ece000 8388608 99712 VX 60 1988 Total: - - 74244096 - - 10700 7426 This has been steady for over an hour which also means that 11.50.xC6 is much slower than 11.70.xC8W4 for BTS index builds. Another post on this thread suggested using xact_ramdirectory="yes", this will use considerably more memory for the index build because it would result in the index being built in memory. -- Mark. Mark Ashworth IBM Informix Extensibility Architect Office phone: +1 (905) 413-5033 Alternate: +1 (905) 697-8094 Email: ashworth@ca.ibm.com Check out my blog ids-bounces@iiug.org wrote on 09/08/2014 06:44:39 PM: > From: "MICHAEL HOFFMAN" <mrh@panix.com> > To: ids@iiug.org, > Date: 09/08/2014 06:45 PM > Subject: Re: VERY slow BTS index build [33740] > Sent by: ids-bounces@iiug.org > > Mark, > That is the kind of response times I expect from Informix. > I have no idea why these builds are taking so long. It seems as if varchar > works faster than char, but they take a few hours as well. > > This system is a fairly idle server, used for QA mostly. When the > BTS build is > running, 'top' shows the Informix oninits sitting above all else, and the > 'top' session next in line -- ie: nothing else is happening. > > I just ran a new test on a different column: char(25) with only *4* > values for > 980K rows. 850K are the same value. This should be a fairly simple index to > create ... after all, a regular index on the column completes in about 3 > minutes. > After an hour-and-a-half, I stopped the test. No reason to wait any longer, > that's just too slow. > > I dropped the Buffers down to 200000 and LRUs at 8. Pushed the SHMVRTSIZE to > 2048000 -- the entire database should fit into that! SHMADD = 256000. > EXTSHMADD = 4096.> > Looking at onstat -p, both Buffer Rates are above 99%. Good! > Looking at onstat -p, both Buffer Rates are above 99%. Good! > Looking at onstat -D shows some writes to bts_temp space (created > the same way > you did, with the '-t' option) and about 108000 reads from the databases > dbspace. > onstat -g opn shows several temp tables being opened and closedconstantly. > > Hmm... after an 1.5 hours, it only did 108K reads? BTS must be sorting each > row as it builds the index? > > Oh, and here's a CRAZY issue: immediately upon starting the build, the engine > dynamically adds *4* "new extension shared memory" segments! By the > time I had > stopped the build, *8 segnemts* had been added. This boosted the virtual > memory to 2077696. > Why would the engine need more VM? As I said, with the boost of SHMVRTSIZE to > 2GB, the entire database can fit there. > > Strange, huh? Art, you got any ideas? > > Thanks again! Really hoping to find an answer so I can convince the Big Boys > to sign off on using BTS. > > Michael > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. >

>> > Oh, and here's a CRAZY issue: immediately upon starting the build, the engine >> > dynamically adds *4* "new extension shared memory" segments! By the >> > time I had >> > stopped the build, *8 segnemts* had been added. This boosted the virtual >> > memory to 2077696. >> > Why would the engine need more VM? As I said, with the boost of SHMVRTSIZE to >> > 2GB, the entire database can fit there. >> >> When BTS creates and index or inserts into an index, rows are inserted >> into the index stages. The first stage is an small in-memory structure >> called a ramdirectory. I typically run >> with EXTSHMADD set to 8192 and it governs the number the size of the VX >> class of memory segments. VX memory segments are associated with VPs like >> the bts VP. >> I have gone to 11.50.xC6 and trying the index build again. I do not see >> a memory leak where the VX segments are growing: Well, I can add this to the "fun" -- I left the build running overnight. (Remember: char(25) field with 4 distinct values over 980K rows) After running for 16 hours, there were **147** VX segments! Most were added at 4196 increments, although a few were larger. I just stopped the build and restarted after setting RESIDENT = -1, and after a half-hour, there are already 19 new segments. So, Mark, since you are getting FAR different results, do you have a suggestion what I can look at which might be causing this? I am scouring all the info I can find on Shared Memory, Resident / Virtual, configurations, etc. I'm going to try dropping the SHMVIRTSIZE back down. It is at 2GB, when it was at 256MB, I didn't think we saw this issue, but I need to clarify. Thanks, Mike

>> Very odd, because that does sound EXACTLY like the symptoms of the dynamic >> VP_MEMORY_CACHE_KB change in 11.70 from STATIC always to DYNAMIC always in >> the early releases to DYNAMIC by default with STATIC as an option in the >> later 11.70 & 12.10 releases. Since you are on 11.50 I wouldn't think that >> this is the problem, but it can't hurt to bring it up to your PMR contact. >> >> Again, adding shared memory segments under Solaris is VERY expensive and >> VERY slow, so with 25+ new segments, that may actually be a bigger part of >> the slowdown than I initially thought. >> >> Art >> Art S. Kagel, Principal Consultant >> ASK Database Management Considering the number of VX segments expanded to 147 by the time I killed the build (after 16 hours or so), that raises a huge red flag. Maybe the issue came about earlier than was reported but users jumped over this version of 11.5? If we cannot figure this out, I will definitely get in touch with our PMR contact (if I can find them). Do you recall what the setting is to switch back from DYNAMIC to STATIC? or is there none? Thanks, Mike

>> Try setting this: >> MULTI_INDEX_SCAN 0 >> It created a memory leak in earlier versions of 11.70. Maybe that is what >> you are hitting. >> Thanks, >> Kate Thanks, Kate. MULTI_INDEX_SCAN is not a documented setting for 11.5 -- weren't multiple index scans introduced in 11.7? Either way, this is an index build, not a query, so it shouldn't be scanning at all. Do you think that still applies? Thanks, Michael

I didn't know it was a setting in 11.70 since it wasn't listed in the config file. So worth a try? Thanks, Kate On Sep 9, 2014, at 11:40 AM, "MICHAEL HOFFMAN" <mrh@panix.com> wrote: >>> Try setting this: >>> MULTI_INDEX_SCAN 0 >>> It created a memory leak in earlier versions of 11.70. Maybe that is what >>> you are hitting. >>> Thanks, >>> Kate > > Thanks, Kate. > MULTI_INDEX_SCAN is not a documented setting for 11.5 -- weren't multiple > index scans introduced in 11.7? Either way, this is an index build, not a > query, so it shouldn't be scanning at all. Do you think that still applies? > > Thanks, > Michael > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. >

If you set the value to 0 and bounce the config you will turn it off completely. I believe you can set the value to static,#### to switch to static. Thanks, Kate On Sep 9, 2014, at 11:35 AM, "MICHAEL HOFFMAN" <mrh@panix.com> wrote: >>> Very odd, because that does sound EXACTLY like the symptoms of the dynamic >>> VP_MEMORY_CACHE_KB change in 11.70 from STATIC always to DYNAMIC always in >>> the early releases to DYNAMIC by default with STATIC as an option in the >>> later 11.70 & 12.10 releases. Since you are on 11.50 I wouldn't think that >>> this is the problem, but it can't hurt to bring it up to your PMR contact. >>> >>> Again, adding shared memory segments under Solaris is VERY expensive and >>> VERY slow, so with 25+ new segments, that may actually be a bigger part of >>> the slowdown than I initially thought. >>> >>> Art >>> Art S. Kagel, Principal Consultant >>> ASK Database Management > > Considering the number of VX segments expanded to 147 by the time I killed the > build (after 16 hours or so), that raises a huge red flag. Maybe the issue > came about earlier than was reported but users jumped over this version of > 11.5? If we cannot figure this out, I will definitely get in touch with our > PMR contact (if I can find them). > > Do you recall what the setting is to switch back from DYNAMIC to STATIC? or is > there none? > > Thanks, > Mike > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. >

Retry with Kate & Art's suggestions. Seems to be similar results. BUT also discovered something else that might shed light: Informix 11.5.FC6 running on a Sun Solaris 10 system. PDQ set to 100. PSORT_NPROCS = 8. changes to onconfig: MULTI_INDEX_SCAN 0 VP_MEMORY_CACHE_KB 819200 (used 40% of 2GB, although SHMTOTAL is 0) Bounced the engine and kicked off the script. Made one adjustment: I am reading the column values into a temp table to put them in memory first. Would that work? Looks like NO. As soon as the index build starts, 3 new extension segments are added; a 4th and 5th added 2 and 5 minutes later. :-( The interesting thing is the results of onstat -D: For the read into temp table, the database dbspace gets 250 reads. For the index build, after 7 minutes, the same space is over 30000 reads! Mike

The setting in 11.70.xC6+ and 12.10 is: VP_MEMORY_CACHE_KB ####,STATIC --or-- VP_MEMORY_CACHE_KB ####,DYNAMIC The latter is the default if you just specify a number and no type. In 11.50 you could only set: VP_MEMORY_CACHE_KB ####which meant STATIC (DYNAMIC didn't exist). That was changed in 11.70.xC1 to mean DYNAMIC with no option to change back to STATIC until the .xC6 release. Art Art S. Kagel, Principal Consultant ASK Database Management Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Tue, Sep 9, 2014 at 11:35 AM, MICHAEL HOFFMAN <mrh@panix.com> wrote: > >> Very odd, because that does sound EXACTLY like the symptoms of the > dynamic > >> VP_MEMORY_CACHE_KB change in 11.70 from STATIC always to DYNAMIC always > in > >> the early releases to DYNAMIC by default with STATIC as an option in the > >> later 11.70 & 12.10 releases. Since you are on 11.50 I wouldn't think > that > >> this is the problem, but it can't hurt to bring it up to your PMR > contact. > >> > >> Again, adding shared memory segments under Solaris is VERY expensive and > >> VERY slow, so with 25+ new segments, that may actually be a bigger part > of > >> the slowdown than I initially thought. > >> > >> Art > >> Art S. Kagel, Principal Consultant > >> ASK Database Management > > Considering the number of VX segments expanded to 147 by the time I killed > the > build (after 16 hours or so), that raises a huge red flag. Maybe the issue > came about earlier than was reported but users jumped over this version of > 11.5? If we cannot figure this out, I will definitely get in touch with our > PMR contact (if I can find them). > > Do you recall what the setting is to switch back from DYNAMIC to STATIC? > or is > there none? > > Thanks, > Mike > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001a11c33b7cc844810502a5c2d5

11.50 didn't have multi-index scans Kate, so the setting will be ignored. Art Art S. Kagel, Principal Consultant ASK Database Management Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Tue, Sep 9, 2014 at 12:44 PM, Kate Bellsouth <katedart@bellsouth.net> wrote: > I didn't know it was a setting in 11.70 since it wasn't listed in the > config > file. So worth a try? > > Thanks, > Kate > > On Sep 9, 2014, at 11:40 AM, "MICHAEL HOFFMAN" <mrh@panix.com> wrote: > > >>> Try setting this: > >>> MULTI_INDEX_SCAN 0 > >>> It created a memory leak in earlier versions of 11.70. Maybe that is > what > >>> you are hitting. > >>> Thanks, > >>> Kate > > > > Thanks, Kate. > > MULTI_INDEX_SCAN is not a documented setting for 11.5 -- weren't multiple > > index scans introduced in 11.7? Either way, this is an index build, not a > > query, so it shouldn't be scanning at all. Do you think that still > applies? > > > > Thanks, > > Michael > > > > > > > > ******************************************************************************* > > Forum Note: Use "Reply" to post a response in the discussion forum. > > > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001a11c221ae40e0090502a5ffd3

Hi Michael, BTS is based on CLucene which is an open source package and it does alot of reads and write to build the index. Its a full text index which is fair bit more complicated to build than a BTree or even an RTree index. You can expect a large number of reads and writes on the sb temp. I have 11.50.FC6 on solaris now and and the index create took significantly longer (12 hr for me). and it only had created 6 VX memory segments (used by BTS) with EXTSHADD set to 8192, I do not know how or why you are getting so many segments created. I have not seen this in connection with BTS. I am not aware of any affects of on BTS by the PDQ settings since BTS is not parallizable. It does not use any sorting facilities in the server either. As Art reported multi index scan are not supported in 11.50, but even going forward, the server does not support multiindex scans for VII based indexes like BTS (or RTree) so I have not seen any effects between the MULTI_INDEX_SCAN and BTS. As I said in an earlier email, there we some performance defects applied to BTS in fixpacks after 11.50.xC6. Are you able to try the latest fixpack for 11.50?? If that works, can you upgrade? If not , it may be time to open a PMR with support for this issue and asked the support to discuss it with me. -- Mark. Mark Ashworth IBM Informix Extensibility Architect Office phone: +1 (905) 413-5033 Alternate: +1 (905) 697-8094 Email: ashworth@ca.ibm.com Check out my blog From: "MICHAEL HOFFMAN" <mrh@panix.com> To: ids@iiug.org, Date: 09/09/2014 01:57 PM Subject: Re: VERY slow BTS index build [33758] Sent by: ids-bounces@iiug.org Retry with Kate & Art's suggestions. Seems to be similar results. BUT also discovered something else that might shed light: Informix 11.5.FC6 running on a Sun Solaris 10 system. PDQ set to 100. PSORT_NPROCS = 8. changes to onconfig: MULTI_INDEX_SCAN 0 VP_MEMORY_CACHE_KB 819200 (used 40% of 2GB, although SHMTOTAL is 0) Bounced the engine and kicked off the script. Made one adjustment: I am reading the column values into a temp table to put them in memory first. Would that work? Looks like NO. As soon as the index build starts, 3 new extension segments are added; a 4th and 5th added 2 and 5 minutes later. :-( The interesting thing is the results of onstat -D: For the read into temp table, the database dbspace gets 250 reads. For the index build, after 7 minutes, the same space is over 30000 reads! Mike ******************************************************************************* Forum Note: Use "Reply" to post a response in the discussion forum.

>> BTS is based on CLucene which is an open source package and it does alot >> of reads and write to build the index. Its a full text index which is >> fair bit more complicated to build than a BTree or even an RTree index. >> You can expect a large number of reads and writes on the sb temp. I have >> 11.50.FC6 on solaris now and and the index create took significantly >> longer (12 hr for me). and it only had created 6 VX memory segments (used >> by BTS) with EXTSHADD set to 8192, I do not know how or why you are >> getting so many segments created. I have not seen this in connection with >> BTS. >> >> As I said in an earlier email, there we some performance defects applied >> to BTS in fixpacks after 11.50.xC6. Are you able to try the latest fixpack >> for 11.50?? If that works, can you upgrade? If not , it may be time to >> open a PMR with support for this issue and asked the support to discuss it >> with me. >> -- Mark. >> Mark Ashworth >> IBM Informix Extensibility Architect Hi Mark, Ah ha! So, it seems we have an issue specifically with Solaris and BTS. Your 12-hour run is much closer in line with mine, and quite different than your original 7-minute test. :-) We are discussing applying the fixpacks for 11.5 to FC8 as an interim solution before the upgrade to 12.1. Thanks for all of your assistance! Mike PS -- My current build has been running for 16 hours and has grabbed 18 VX segments, with EXTSHMADD set to 40960! Ugh! I will add another response off of the main one, with my "memory leak" findings.

Hi Michael, Actually the problem is with BTS in 11.50.xC6 for all platforms, not just solaris. -- Mark. Mark Ashworth IBM Informix Extensibility Architect Office phone: +1 (905) 413-5033 Alternate: +1 (905) 697-8094 Email: ashworth@ca.ibm.com Check out my blog From: "MICHAEL HOFFMAN" <mrh@panix.com> To: ids@iiug.org, Date: 09/10/2014 10:39 AM Subject: Re: VERY slow BTS index build [33771] Sent by: ids-bounces@iiug.org >> BTS is based on CLucene which is an open source package and it does alot >> of reads and write to build the index. Its a full text index which is >> fair bit more complicated to build than a BTree or even an RTree index. >> You can expect a large number of reads and writes on the sb temp. I have >> 11.50.FC6 on solaris now and and the index create took significantly >> longer (12 hr for me). and it only had created 6 VX memory segments (used >> by BTS) with EXTSHADD set to 8192, I do not know how or why you are >> getting so many segments created. I have not seen this in connection with >> BTS. >> >> As I said in an earlier email, there we some performance defects applied >> to BTS in fixpacks after 11.50.xC6. Are you able to try the latest fixpack >> for 11.50?? If that works, can you upgrade? If not , it may be time to >> open a PMR with support for this issue and asked the support to discuss it >> with me. >> -- Mark. >> Mark Ashworth >> IBM Informix Extensibility Architect Hi Mark, Ah ha! So, it seems we have an issue specifically with Solaris and BTS. Your 12-hour run is much closer in line with mine, and quite different than your original 7-minute test. :-) We are discussing applying the fixpacks for 11.5 to FC8 as an interim solution before the upgrade to 12.1. Thanks for all of your assistance! Mike PS -- My current build has been running for 16 hours and has grabbed 18 VX segments, with EXTSHMADD set to 40960! Ugh! I will add another response off of the main one, with my "memory leak" findings. ******************************************************************************* Forum Note: Use "Reply" to post a response in the discussion forum.

Well, this has been a long and crazy thread, and it's about time to wrap it up, probably without a solution other than: Time to Upgrade, BTS is not quite ready in 11.5.FC6 on Solaris 10. (and there's the pertinent system info!) [While researching online, I found Informix Problem IC97110. This led me to some memory stats, and I think the bug is here] My current test has run for 16+ hours, building a BTS index on a char(25) field with 980K rows. There are only *4* distinct values. Yes, it's a dumb index for BTS, but that's why I chose it... should be super easy to build. I am the only user also. Pretty much on the entire server! There is definitely a memory leak *somewhere*. Tons of virtual memory was given at the start, yet th query has grabbed 16 extra segments -- with EXTSHMADD = 40960!!! Here are the stats, with comments below each: onstat -p IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 14:23:57 --3368960 Kbytes Profile dskreads pagreads bufreads %cached dskwrits pagwrits bufwrits %cached 456534 460955 1322622525 99.97 3431698 3449860 435702023 99.21 isamtot open start read write rewrite delete commit rollbk 1914676941 40550611 99290 3170320 1069320 19813 5233 30736 0 gp_read gp_write gp_rewrt gp_del gp_alloc gp_free gp_curs 824302364 237917 197052569 237829 1 0 7 ovlock ovuserthread ovbuff usercpu syscpu numckpts flushes 0 0 0 51867.57 88.61 470 390 bufwaits lokwaits lockreqs deadlks dltouts ckpwaits compress seqscans 5762 0 946555532 0 0 380 9856 11291 ixda-RA idx-RA da-RA RA-pgsused lchwaits 1143 74 372138 373269 1992 These look FANTASTIC, right? 99% for buffer ratios. Read-Ahead in a good range. But User CPU is really high, and isam tot is through the roof! onstat -P (snipped many buffers, only showing large ones, and the final totals)Buffer pool page size: 2048 partnum total btree data other dirty 0 46397 0 46395 2 46389 1048577 3331 0 29 3302 0 4194571 59889 0 59798 91 0 23069298 2916 2916 0 0 0 28311557 82455 0 82435 20 306 Totals: 200000 4115 190883 5002 46716 Percentages: Data 95.44 Btree 2.06 Other 2.50 Good percentages... 95% Data, only 2% 'wasted' buffers. onstat -D (removed the irrelevant dbspaces and chunks. VERY little activity)12f2e5028 1 0x20001 1 1 2048 N informix rootdbs 1302a8e28 4 0x1 7 1 2048 N informix chardb 1302aa9b8 21 0x20001 50 1 2048 N informix llogs 1302aae80 24 0x1 52 1 2048 N informix physical 1302ac1c0 26 0x68001 61 2 2048 N SB informix bts_sbpace 1302ac358 27 0x4a001 62 1 2048 N UB informix bts_temp 12f2e51c0 1 1 50 10930 13410 /dev/md/rdsk/d118 1302ad028 7 4 50 365297 4 /dev/md/rdsk/d114 1302b25f8 50 21 50 38 20153 /dev/md/rdsk/d151 1302b29d8 52 24 50 3 8048 /dev/md/rdsk/d152 1302b3bc8 61 26 0 65535 5 /dev/md/rdsk/d136 1302b3db8 62 27 0 80 3448422 /dev/md/rdsk/d137 A lot of reads and writes to the main db dbspace and the bts_temp space. Nothing written yet to the main bts sbspace! Now for the problem areas: onstat -g segSegment Summary: id key addr size ovhd class blkused blkfree 16777320 525a4801 10a000000 596639744 7425232 R 145548 116 16777321 525a4802 12d900000 2097152000 24577792 V 45397 466603 16777322 525a4803 1aa900000 1048576 13552 M 159 97 16777323 525a4804 1aaa00000 41943040 493072 VX 5638 4602 16777324 525a4805 1ad200000 41943040 493072 VX 180 10060 16777325 525a4806 1afa00000 41943040 493072 VX 179 10061 16777326 525a4807 1b2200000 41943040 493072 VX 178 10062 16777327 525a4808 1b4a00000 41943040 493072 VX 177 10063 16777328 525a4809 1b7200000 41943040 493072 VX 177 10063 16777329 525a480a 1b9a00000 41943040 493072 VX 176 10064 16777330 525a480b 1bc200000 41943040 493072 VX 175 10065 16777331 525a480c 1bea00000 41943040 493072 VX 174 10066 16777332 525a480d 1c1200000 41943040 493072 VX 175 10065 16777333 525a480e 1c3a00000 41943040 493072 VX 172 10068 16777334 525a480f 1c6200000 41943040 493072 VX 172 10068 16777335 525a4810 1c8a00000 41943040 493072 VX 170 10070 16777336 525a4811 1cb200000 41943040 493072 VX 165 10075 16777337 525a4812 1cda00000 41943040 493072 VX 121 10119 16777338 525a4813 1d0200000 41943040 493072 VX 121 10119 16777339 525a4814 1d2a00000 41943040 493072 VX 121 10119 16777340 525a4815 1d5200000 41943040 493072 VX 121 10119 Total: - - 3449815040 - - 199496 642744 Look at that ugliness! So many VX extensions, and most are UNUSED! onmode -F does not free them either. After monitoring for a while, I do see earlier ones being re-used. What could BTS be storing and why does it keep grabbing more? onstat -g mem (AHA! Maybe? I cut this list considerably. Explain below.)Pool Summary: name class addr totalsize freesize #allocfrag #freefrag RTN.35.65 VX 1abb93040 19415040 13781040 21460 9187 TRX.35.65 VX 1aaa81040 7745536 164056 487 240 rsam V 12f2e4040 18849792 246752 37046 324 DefConvWrit V 12fe8e040 1167360 1152504 103 32 35 V 130be5040 684032 135880 643 132 global V 12f071040 17203200 755888 1977 42 Blkpool Summary: name class addr size #blks mt V 12f0849b8 3383296 42 global V 12f07f618 0 0 I cut out any pools with under 100000 totalsize. Also compared to a different system running well and removed any pools with similar values. What is left are the rsam, DefConvWrit (?), TRX and RTN pools for session 35 -- mine! onstat -u12f4510c0 --BP--- 35 devdba 2 0 0 318303 369793 4916 What is using the memory for those pools? Well, I don't know what rsam is doing, but TRX and RTN are all SAPI -- the Datablade API! onstat -g ufr rsamMemory usage for pool name rsam: size memid 3288 overhead 51032 rsam 273448 rstcb 101416 trans 7637808 partn 10536048 keys onstat -g ufr DefConvWritMemory usage for pool name DefConvWrit: size memid 3288 overhead 11568 aio onstat -g ufr RTN.35.65Memory usage for pool name RTN.35.65: size memid 3288 overhead 4018920 SAPI onstat -g ufr TRX.35.65Memory usage for pool name TRX.35.65: size memid 3288 overhead 1576 SAPI Named 7576616 SAPI So there it is. And it relates perfectly back to the Problem noted at the top. That was for Informix 12.1, but I'm guessing that it existed long before and no one noticed, due to specific configurations. Oh, here are the important Config settings I am using for this run: PHYSFILE 1000000 PHYSBUFF 128 DBSPACETEMP dbtemp:dbtemp2 SBSPACETEMP bts_temp SBSPACENAME bts_sbpace MULTIPROCESSOR 1 VPCLASS cpu,num=3,noage VP_MEMORY_CACHE_KB 819200 SINGLE_CPU_VP 0 MULTI_INDEX_SCAN 0 VPCLASS aio,num=2,noage CLEANERS 8AUTO_AIOVPS 1 DIRECT_IO 0 VPCLASS bts,num=3,noyield LOCKS 1024000 DEF_TABLE_LOCKMODE ROW RESIDENT 0 SHMVIRTSIZE 2048000 SHMADD 256000 EXTSHMADD 40960 SHMTOTAL 0 STMT_CACHE 1 STMT_CACHE_HITS 1 STMT_CACHE_SIZE 1024 STMT_CACHE_NOLIMIT 0 STMT_CACHE_NUMPOOL 1 STACKSIZE 64 FILLFACTOR 90 MAX_FILL_DATA_PAGES 0 BTSCANNER num=8,threshold=5000,rangesize=-1,alice=6,compression=default ONLIDX_MAXMEM 5120 DS_NONPDQ_QUERY_MEM 128000 AUTO_LRU_TUNING 1 BUFFERPOOL size=2K,buffers=200000,lrus=8,lru_min_dirty=80.000000,lru_max_dirty=90.000000 Thanks for