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
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.ibm.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 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 16169942 1842 560632 748 59 519 109 0
gp_read gp_write gp_rewrt gp_del gp_alloc gp_free gp_curs
227801080 100794 79180097 100714 3 0 13
ovlock ovuserthread ovbuff usercpu syscpu numckpts flushes
0 0 0 17688.58 23.60 4 3
bufwaits lokwaits lockreqs deadlks dltouts ckpwaits compress seqscans
2430 0 277172445 0 0 1 43 381
ixda-RA idx-RA da-RA RA-pgsused lchwaits
96 15 225454 225509 66
onstat -g mgm
---------------
IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:56:21 --
1278976 Kbytes
Memory Grant Manager (MGM)
--------------------------
MAX_PDQPRIORITY: 100
DS_MAX_QUERIES: 6
DS_MAX_SCANS: 1048576
DS_NONPDQ_QUERY_MEM: 128 KB
DS_TOTAL_MEMORY: 768 KB
Queries: Active Ready Maximum
1 0 6
Memory: Total Free Quantum
(KB) 768 0 128
Scans: Total Free Quantum
1048576 1048575 1
Load Control: (Memory) (Scans) (Priority) (Max Queries) (Reinit)
Gate 1 Gate 2 Gate 3 Gate 4 Gate 5
(Queue Length) 0 0 0 0 0
Active Queries:
---------------
Session Query Priority Thread Memory Scans Gate
27 146427c08 100 1463cad40 0/96 0/1 -
Ready Queries: None
Free Resource Average # Minimum #
-------------- --------------- ---------
Memory 0.0 +- 0.0 0
Scans 1048575.0 +- 0.0 1048575
Queries Average # Maximum # Total #
-------------- --------------- --------- -------
Active 1.0 +- 0.0 1 1
Ready 0.0 +- 0.0 0 0
Resource/Lock Cycle Prevention count: 0
onstat -g act
---------------
IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:57:18 --
1278976 Kbytes
Running threads:
tid tcb rstcb prty status vp-class name
9 145ec1830 0 1 running 1cpu* tlitcppoll
10 145f0f638 0 1 running 6cpu* tlitcppoll
11 145e6a2a8 0 1 running 14shm* sm_poll
57 1463cad40 145366e00 1 running 3bts* sqlexec
onstat -g cpu
--------------
24 kaio 7cpu* 09/05 15:18:54 6.7544 78285 IO Idle
42 kaio 6cpu* 09/05 15:45:16 7.3771 38429 IO Idle
43 kaio 1cpu* 09/05 15:18:54 3.2953 29975 IO Idle
57 sqlexec 3bts* 09/05 15:45:16 18484.4641 20946 running
59 kaio 3bts* 09/05 10:37:09 0.0826 322 IO Idle
onstat -g iov
--------------
IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 05:10:31 --
1278976 Kbytes
AIO I/O vps:
class/vp/id s io/s totalops dskread dskwrite dskcopy wakeups io/wup errors
tempops
fifo 12 0 i 0.0 0 0 0 0 1 0.0 0 0
kio -1 0 i 2.1 39194 39083 111 0 78284 0.5 0 0
kio -1 1 i 1.6 29774 26281 3493 0 38440 0.8 0 0
kio -1 2 i 0.8 15017 14978 39 0 29973 0.5 0 0
kio -1 3 i 0.0 160 160 0 0 320 0.5 0 0
msc 11 0 i 0.0 6 0 0 0 7 0.9 0 6
aio 10 0 i 0.0 257 17 2 0 258 1.0 0 0
aio 13 1 i 0.0 0 0 0 0 1 0.0 0 0
pio 9 0 i 0.0 0 0 0 0 1 0.0 0 0
lio 8 0 i 0.0 0 0 0 0 1 0.0 0 0
onstat -g glo
-------------
IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 05:14:11 --
127
8976 Kbytes
MT global info:
sessions threads vps lngspins
1 34 14 0
sched calls thread switches yield 0 yield n yield forever
total: 899787 730236 83892 245297 219342
per sec: 0 0 0 0 0
Virtual processor summary:
class vps usercpu syscpu total
cpu 3 25.00 14.11 39.11
aio 2 0.38 0.87 1.25
shm 1 0.14 0.26 0.40
lio 1 0.16 0.27 0.43
pio 1 0.18 0.35 0.53
adm 1 1.10 1.66 2.76
msc 1 0.00 0.00 0.00
fifo 1 0.19 0.35 0.54
bts 3 18780.10 6.70 18786.80
total 14 18807.25 24.57 18831.82
Individual virtual processors:
vp pid class usercpu syscpu total Thread Eff
1 3391 cpu 5.73 4.27 10.00 10.86 92%
2 3392 adm 1.10 1.66 2.76 0.00 0%
3 3393 bts 18779.43 6.12 18785.55 18797.89 99%
4 3394 bts 0.34 0.28 0.62 0.00 0%
5 3395 bts 0.33 0.30 0.63 0.00 0%
6 3396 cpu 11.99 6.25 18.24 19.59 93%
7 3397 cpu 7.28 3.59 10.87 15.15 71%
8 3398 lio 0.16 0.27 0.43 0.43 100%
9 3399 pio 0.18 0.35 0.53 0.53 100%
10 3400 aio 0.18 0.50 0.68 1.83 37%
11 3401 msc 0.00 0.00 0.00 0.01 0%
12 3402 fifo 0.19 0.35 0.54 0.54 100%
13 3403 aio 0.20 0.37 0.57 0.57 100%
14 3404 shm 0.14 0.26 0.40 NA NA
tot 18807.25 24.57 18831.82
onstat -F
----------
IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 05:06:38 --
1278976 Kbytes
Fg Writes LRU Writes Chunk Writes
0 0 52710
onstat -c
-----------
IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line -- Up 04:58:59 --
1
278976 Kbytes
PHYSFILE 1000000
PLOG_OVERFLOW_PATH /soft/prodinformix/foghorn/tmp
PHYSBUFF 128
LOGFILES 54
LOGSIZE 25000
DYNAMIC_LOGS 2
LOGBUFF 64
LTXHWM 70
LTXEHWM 80
DBSPACETEMP dbtemp:dbtemp2
#SBSPACETEMP bts_temp:bts_temp1:bts_temp2
SBSPACETEMP bts_temp
SBSPACENAME bts_sbpace
SYSSBSPACENAME
ONDBSPACEDOWN 1
MULTIPROCESSOR 1
VPCLASS cpu,num=3,noage
VP_MEMORY_CACHE_KB 0
SINGLE_CPU_VP 0
VPCLASS aio,num=2,noage
CLEANERS 8
AUTO_AIOVPS 1
DIRECT_IO 0
VPCLASS bts,num=3,noyield
LOCKS 512000
DEF_TABLE_LOCKMODE ROW
RESIDENT 0
SHMBASE 0x10a000000
#SHMBASE 0x10A000000L
SHMVIRTSIZE 256000
SHMADD 64000
EXTSHMADD 4096
SHMTOTAL 0
SHMVIRT_ALLOCSEG 0.000000
SHMNOACCESS formix-1150fc5.tar
CKPTINTVL 10800
AUTO_CKPTS 1
RTO_SERVER_RESTART 0
BLOCKTIMEOUT 3600
TXTIMEOUT 300
DEADLOCK_TIMEOUT 60
HETERO_COMMIT 0
STMT_CACHE 1
STMT_CACHE_HITS 1
STMT_CACHE_SIZE 1024
STMT_CACHE_NOLIMIT 0
STMT_CACHE_NUMPOOL 1
FILLFACTOR 90
MAX_FILL_DATA_PAGES 0
BTSCANNER num=1,threshold=5000,rangesize=-1,alice=6,compression=default
ONLIDX_MAXMEM 5120
MAX_PDQPRIORITY 100
DS_MAX_QUERIES
DS_TOTAL_MEMORY
DS_MAX_SCANS 1048576
DS_NONPDQ_QUERY_MEM 128
DATASKIP OFF
RA_PAGES 64
RA_THRESHOLD 16
BUFFERPOOL
size=2K,buffers=400000,lrus=10,lru_min_dirty=80.000000,lru_max_dirty=90.000000
AUTO_LRU_TUNING 1
*******************************************************************************
Forum Note: Use "Reply" to post a response in the discussion forum.
