Problem with ONBAR: unusually slow on IDS 11.50.FC
An IDS 11.50.FC5 instance on AIX took hours in the pre-backup ON-Bar query 'select sum(npused) from sysdbspaces, sysptnhdr ...', while identical instances ran it instantly. Fernando suggested it matched APAR IC71702 (fixed in 11.50.FC8W2) and advised opening a PMR, noting the slow instance likely has far more partitions. Art Kagel diagnosed badly fragmented Tablespace Tablespaces (~150 dbspaces, tiny default extent sizes), since sysptnhdr has no index and must scan all extents; fix is to size TBLTBLFIRST/TBLTBLNEXT and onspaces -ef/-en and rebuild/move dbspaces. The poster opened a PMR and planned a reorg; no confirmed outcome is recorded.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Hi,
A client of ours is runnning IDS 11.50.FC5 on AIX and is facing a
problem with a backup running ONBAR.
It runs fine on several instances on different machines, but is very
slow on one instance. All of the instances are setup the same way along
the same model and the same ONCONFIG.
ONBAR runs a particular query before performing the backup:
*select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = ? *
This query goes on for ever (*few hours*). We tried to run a query on
sysptnhdr by itself and sysdbspaces also by itself. It seems that the query on
sysptnhdr is very very slow. The same query runs very fast (instantanious) on
the other instances.
We tried to rebuild the sysmaster databse, but nothing came out it.
Here is more info on this session: any ideas ?
-------------------------------------------------------------------------
tid tcb rstcb prty status vp-class name
2 7000000b162d9f0 0 1 IO Idle 10lio* lio vp 0
3 7000000b166a288 0 1 IO Idle 11pio* pio vp 0
4 7000000b1692288 0 1 IO Idle 12aio* aio vp 0
5 7000000b16ba288 0 1 IO Idle 13msc* msc vp 0
6 7000000b16f2528 7000000b0adc028 3 sleeping secs: 1 1cpu main_loop()
7 7000000b1638a50 0 1 running 14soc* soctcppoll
8 7000000b15236c0 0 2 sleeping forever 1cpu* soctcplst
9 7000000b1692830 0 2 sleeping forever 3cpu* soctcplst
10 7000000b16ba4e8 7000000b0adc858 1 sleeping secs: 1 1cpu flush_sub(0)
11 7000000b16ba7c0 7000000b0add088 1 sleeping secs: 1 1cpu flush_sub(1)
12 7000000b16baa98 7000000b0add8b8 1 sleeping secs: 1 1cpu flush_sub(2)
13 7000000b16bad70 7000000b0ade0e8 1 sleeping secs: 1 1cpu flush_sub(3)
14 7000000b1617300 0 3 running 3cpu* kaio
31 7000000b196a808 0 3 IO Idle 1cpu* kaio
37 7000000b1a7a388 7000000b0ade918 2 sleeping secs: 1 1cpu aslogflush
38 7000000b1a7a660 7000000b0adf148 1 sleeping secs: 125 1cpu btscanner_0
60 7000000b211c928 7000000b0ae09d8 3 sleeping secs: 1 1cpu* onmode_mon
61 7000000b211cb88 7000000b0ae01a8 3 sleeping secs: 1 1cpu periodic
62 7000000b257e028 0 3 IO Idle 4cpu* kaio
67 7000000b23ec418 7000000b0ae1a38 1 sleeping secs: 10 1cpu dbScheduler
69 7000000b2337028 7000000b0ae1208 1 sleeping forever 3cpu dbWorker1
70 7000000b2373568 7000000b0ae2268 1 sleeping forever 1cpu dbWorker2
73 7000000b21c5148 0 3 IO Idle 6cpu* kaio
76 7000000b21c55e8 0 3 IO Idle 7cpu* kaio
77 7000000b21c5ad8 7000000b0adf978 1 cond wait bp_cond 1cpu bf_priosweep()
78 7000000b22131e8 0 3 IO Idle 5cpu* kaio
87 7000000b5fd5550 0 3 IO Idle 9cpu* kaio
93 7000000b5fd5bc8 0 3 IO Idle 8cpu* kaio
* 129 7000000b241a930 7000000b0ae3af8 1 IO Wait 3cpu ontape*
IBM Informix Dynamic Server Version 11.50.FC5 -- On-Line -- Up 02:45:14 --3142096 Kbytes
Stack for thread: 129 ontapebase: 0x07000000b603d000
len: 135168
pc: 0x00000001000429b0
tos: 0x07000000b605a3b0
state: sleeping
vp: 3
0x00000001000429b0 (oninit)yield_processor_mvp
0x000000010004d400 (oninit)mt_yield
0x00000001000d1798 (oninit)mt_aio_wait
0x00000001000d1cb0 (oninit)mt_aio_start
0x00000001001e8268 (oninit)chunkio_int
0x00000001001e5ea8 (oninit)chunkio
0x00000001001ea52c (oninit)physio
0x00000001001ef024 (oninit)buffget
0x00000001001978c0 (oninit)pthdrgetx
0x000000010019cf80 (oninit)ptalloc
0x0000000100348664 (oninit)nxtpartp
0x0000000100345898 (oninit)prptnhdr
0x000000010033e064 (oninit)pstread
0x0000000100327288 (oninit)pst_rsread
0x00000001003306e8 (oninit)rsread
0x00000001004500fc (oninit)fmread
0x00000001007e811c (oninit)readseq
0x00000001007e883c (oninit)gettupl
0x00000001007ebc78 (oninit)scan_next
0x000000010089d57c (oninit)hjoin_open
0x0000000100bf41d0 (oninit)group_open
0x0000000100551718 (oninit)prepselect
0x0000000100458130 (oninit)excommand
0x000000010041c464 (oninit)sq_exselect
0x00000001002187a0 (oninit)sqmain
0x0000000100578b50 (oninit)listen_verify
0x0000000100577294 (oninit)spawn_thread
0x0000000100d0f93c (oninit)startup
tid name rstcb flags curstk status
129 ontape 7000000b0ae3af8 Y--PR-M 12720 cond wait pt_448a8d -
Memory pools count 2
name class addr totalsize freesize #allocfrag #freefrag
92 V 7000000b2307040 229376 19480 293 27
92*O0 V 7000000b5fe9040 4096 808 1 1
name free used name free used
overhead 0 6576 mtmisc 0 144
scb 0 144 opentable 0 7752
filetable 0 1936 ru 0 600
log 0 16536 temprec 0 2208
keys 0 208 ralloc 0 128072
gentcb 0 1584 ostcb 0 3400
sort 0 104 sqscb 0 21696
sql 0 72 hashfiletab 0 552
osenv 0 3376 buft_buffer 0 4216
sqtcb 0 10760 fragman 0 776
shmblklist 0 704 udr 0 1768
sqscb info
scb sqscb optofc pdqpriority sqlstats optcompind directives
7000000b24e9110 7000000b274c028 0 0 0 0 1
Sess SQL Current Iso Lock SQL ISAM F.E.
Id Stmt type Database Lvl Mode ERR ERR Vers Explain
92 SELECT sysmaster RR Wait 300 0 0 9.24 Off
Current SQL statement :
select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where D
. dbsnum = TRUNC ( P . partnum/ 1048576 ) and name = ?
Host variables :
address type flags value
-----------------------------------------
0x07000000b5a2d268 CHAR 0x000 db11_13trnr
Last parsed SQL statement :
select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where D
. dbsnum = TRUNC ( P . partnum/ 1048576 ) and name = ?
mpm13trnr_prodappl(ifx/ifx) /tmp> more sqexplain.out
QUERY: (OPTIMIZATION TIMESTAMP: 02-22-2011 13:58:12)
------
select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = "de07_13trnr"
Estimated Cost: 30
Estimated # of Rows Returned: 1
1) ifx.d: INDEX PATH
Filters: ifx.d.name = 'de07_13trnr'
(1) Index Name: informix.sysdbstab_dbsnum
Index Keys: dbsnum
Lower Index Filter: ifx.d.dbsnum> 0
2) ifx.p: SEQUENTIAL SCAN
DYNAMIC HASH JOIN
Dynamic Hash Filters: ifx.d.dbsnum = trunc(ifx.p.partnum / 1048576 )
UDRs in query:
--------------
UDR id : 386
UDR name: bitval
UDR id : 386
UDR name: bitval
UDR id : 386
UDR name: bitval
UDR id : 386
UDR name: bitval
*Khaled Bentebal
Email: khaled.bentebal@consult-ix.fr*
Hello,
It looks like APAR IC71702
https://www-304.ibm.com/support/entdocview.wss?uid=swg1IC71702
It's fixed in 11.50.FC8W2
You may want to open a PMR for further details.
Check that the "slow" instance has much more partitions (either table,
indexes or fragments) than the other(s).
Regards.
On Wed, Feb 23, 2011 at 10:52 PM, Khaled Bentebal <
khaled.bentebal@consult-ix.fr> wrote:
> Hi,
>
> A client of ours is runnning IDS 11.50.FC5 on AIX and is facing a
> problem with a backup running ONBAR.
>
> It runs fine on several instances on different machines, but is very
> slow on one instance. All of the instances are setup the same way along
> the same model and the same ONCONFIG.
>
> ONBAR runs a particular query before performing the backup:
> *select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
> D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = ? *
>
> This query goes on for ever (*few hours*). We tried to run a query on
> sysptnhdr by itself and sysdbspaces also by itself. It seems that the query
> on
> sysptnhdr is very very slow. The same query runs very fast (instantanious)
> on
> the other instances.
> We tried to rebuild the sysmaster databse, but nothing came out it.
>
> Here is more info on this session: any ideas ?
> -------------------------------------------------------------------------
> tid tcb rstcb prty status vp-class name
> 2 7000000b162d9f0 0 1 IO Idle 10lio* lio vp 0
> 3 7000000b166a288 0 1 IO Idle 11pio* pio vp 0
> 4 7000000b1692288 0 1 IO Idle 12aio* aio vp 0
> 5 7000000b16ba288 0 1 IO Idle 13msc* msc vp 0
> 6 7000000b16f2528 7000000b0adc028 3 sleeping secs: 1 1cpu main_loop()
> 7 7000000b1638a50 0 1 running 14soc* soctcppoll
> 8 7000000b15236c0 0 2 sleeping forever 1cpu* soctcplst
> 9 7000000b1692830 0 2 sleeping forever 3cpu* soctcplst
> 10 7000000b16ba4e8 7000000b0adc858 1 sleeping secs: 1 1cpu flush_sub(0)
> 11 7000000b16ba7c0 7000000b0add088 1 sleeping secs: 1 1cpu flush_sub(1)
> 12 7000000b16baa98 7000000b0add8b8 1 sleeping secs: 1 1cpu flush_sub(2)
> 13 7000000b16bad70 7000000b0ade0e8 1 sleeping secs: 1 1cpu flush_sub(3)
> 14 7000000b1617300 0 3 running 3cpu* kaio
> 31 7000000b196a808 0 3 IO Idle 1cpu* kaio
> 37 7000000b1a7a388 7000000b0ade918 2 sleeping secs: 1 1cpu aslogflush
> 38 7000000b1a7a660 7000000b0adf148 1 sleeping secs: 125 1cpu btscanner_0
> 60 7000000b211c928 7000000b0ae09d8 3 sleeping secs: 1 1cpu* onmode_mon
> 61 7000000b211cb88 7000000b0ae01a8 3 sleeping secs: 1 1cpu periodic
> 62 7000000b257e028 0 3 IO Idle 4cpu* kaio
> 67 7000000b23ec418 7000000b0ae1a38 1 sleeping secs: 10 1cpu dbScheduler
> 69 7000000b2337028 7000000b0ae1208 1 sleeping forever 3cpu dbWorker1
> 70 7000000b2373568 7000000b0ae2268 1 sleeping forever 1cpu dbWorker2
> 73 7000000b21c5148 0 3 IO Idle 6cpu* kaio
> 76 7000000b21c55e8 0 3 IO Idle 7cpu* kaio
> 77 7000000b21c5ad8 7000000b0adf978 1 cond wait bp_cond 1cpu bf_priosweep()
> 78 7000000b22131e8 0 3 IO Idle 5cpu* kaio
> 87 7000000b5fd5550 0 3 IO Idle 9cpu* kaio
> 93 7000000b5fd5bc8 0 3 IO Idle 8cpu* kaio
> * 129 7000000b241a930 7000000b0ae3af8 1 IO Wait 3cpu ontape*
>
> IBM Informix Dynamic Server Version 11.50.FC5 -- On-Line -- Up 02:45:14 --> 3142096 Kbytes
>
> Stack for thread: 129 ontape> base: 0x07000000b603d000
>
> len: 135168
>
> pc: 0x00000001000429b0
>
> tos: 0x07000000b605a3b0
> state: sleeping
>
> vp: 3
>
> 0x00000001000429b0 (oninit)yield_processor_mvp
> 0x000000010004d400 (oninit)mt_yield
> 0x00000001000d1798 (oninit)mt_aio_wait
> 0x00000001000d1cb0 (oninit)mt_aio_start
> 0x00000001001e8268 (oninit)chunkio_int
> 0x00000001001e5ea8 (oninit)chunkio
> 0x00000001001ea52c (oninit)physio
> 0x00000001001ef024 (oninit)buffget
> 0x00000001001978c0 (oninit)pthdrgetx
> 0x000000010019cf80 (oninit)ptalloc
> 0x0000000100348664 (oninit)nxtpartp
> 0x0000000100345898 (oninit)prptnhdr
> 0x000000010033e064 (oninit)pstread
> 0x0000000100327288 (oninit)pst_rsread
> 0x00000001003306e8 (oninit)rsread
> 0x00000001004500fc (oninit)fmread
> 0x00000001007e811c (oninit)readseq
> 0x00000001007e883c (oninit)gettupl
> 0x00000001007ebc78 (oninit)scan_next
> 0x000000010089d57c (oninit)hjoin_open
> 0x0000000100bf41d0 (oninit)group_open
> 0x0000000100551718 (oninit)prepselect
> 0x0000000100458130 (oninit)excommand
> 0x000000010041c464 (oninit)sq_exselect
> 0x00000001002187a0 (oninit)sqmain
> 0x0000000100578b50 (oninit)listen_verify
> 0x0000000100577294 (oninit)spawn_thread
> 0x0000000100d0f93c (oninit)startup
>
> tid name rstcb flags curstk status
> 129 ontape 7000000b0ae3af8 Y--PR-M 12720 cond wait pt_448a8d -
>
> Memory pools count 2
> name class addr totalsize freesize #allocfrag #freefrag
> 92 V 7000000b2307040 229376 19480 293 27
> 92*O0 V 7000000b5fe9040 4096 808 1 1
>
> name free used name free used
> overhead 0 6576 mtmisc 0 144
> scb 0 144 opentable 0 7752
> filetable 0 1936 ru 0 600
> log 0 16536 temprec 0 2208
> keys 0 208 ralloc 0 128072
> gentcb 0 1584 ostcb 0 3400
> sort 0 104 sqscb 0 21696
> sql 0 72 hashfiletab 0 552
> osenv 0 3376 buft_buffer 0 4216
> sqtcb 0 10760 fragman 0 776
> shmblklist 0 704 udr 0 1768
>
> sqscb info
> scb sqscb optofc pdqpriority sqlstats optcompind directives
> 7000000b24e9110 7000000b274c028 0 0 0 0 1
>
> Sess SQL Current Iso Lock SQL ISAM F.E.
> Id Stmt type Database Lvl Mode ERR ERR Vers Explain
> 92 SELECT sysmaster RR Wait 300 0 0 9.24 Off
>
> Current SQL statement :
>
> select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where D
>
> .. dbsnum = TRUNC ( P . partnum/ 1048576 ) and name = ?
>
> Host variables :
>
> address type flags value
>
> -----------------------------------------
>
> 0x07000000b5a2d268 CHAR 0x000 db11_13trnr
>
> Last parsed SQL statement :
>
> select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where D
>
> .. dbsnum = TRUNC ( P . partnum/ 1048576 ) and name = ?
>
> mpm13trnr_prodappl(ifx/ifx) /tmp> more sqexplain.out
>
> QUERY: (OPTIMIZATION TIMESTAMP: 02-22-2011 13:58:12)
> ------
> select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
> D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = "de07_13trnr"
>
> Estimated Cost: 30
> Estimated # of Rows Returned: 1
>
> 1) ifx.d: INDEX PATH
>
> Filters: ifx.d.name = 'de07_13trnr'
>
> (1) Index Name: informix.sysdbstab_dbsnum
>
> Index Keys: dbsnum
>
> Lower Index Filter: ifx.d.dbsnum> 0
>
> 2) ifx.p: SEQUENTIAL SCAN
>
> DYNAMIC HASH JOIN
>
> Dynamic Hash Filters: ifx.d.dbsnum = trunc(ifx.p.partnum / 1048576 )
>
> UDRs in query:
> --------------
>
> UDR id : 386
>
> UDR name: bitval
>
> UDR id : 386
>
> UDR name: bitval
>
> UDR id : 386
>
> UDR name: bitval
>
> UDR id : 386
>
> UDR name: bitval
>
> *Khaled Bentebal
>
> Email: khaled.bentebal@consult-ix.fr*
>
>
>
>
*******************************************************************************
> Forum No
I suspect that sysmaster isn't the problem, it is that your Tablespace
Tablespaces have too many extents. This can happen if you have lots of
dbspaces and a large number of tables, indexes, and fragments of tables and
indexes spread across them.
Every table in the system has a partition header page, also known as its
Tablespace Tablespace page. The descriptive and performance profile data
from these header pages are what are displayed by the sysmaster pseudo
tables sysptnhdr and sysactptnhdr (the former is just an older version of
the later included for backward compatibility). The Tablespace Tablespace
is treated as a table by the server with a partition in each dbspace which
holds the partition header pages for all tables, indexes, and fragments of
tables and indexes that are resident in that dbspace. What has happened
is that when you creating your tables and indexes the Tablespace Tablespace
became fragmented within each dbspace. Since this is not an 'actual' table,
it has no indexes, so searching it, as onbar does with the query you posted,
requires a sequential scan of all of those fragmented extents. By default,
the initial and next extent sizes for the Tablespace Tablespace for the root
chunk are 250 K and 4 K respectively. Other dbspaces default to even lower
values: 50 pages (using the dbspace's pagesize) and 4 pages unless you
modified those values with the onspaces -ef and -en options when you created
the dbspaces. There are now two ONCONFIG parameters, TBLTBLFIRST and
TBLTBLNEXT, that control the initial extent sizing for this structure in the
root dbspace, however, it is only effective for the root dbspace when the
server is initialized.
You can determine how big these parameters need to be set to for each
dbspace by using the following select:
select dbsname, count(*) as num_extents, sum( size * pagesize / 1024) astotal_kb
from sysextents se, sysdbspaces sd
where se.tabname matches 'TBL*'
and se.dbsname = sd.name
group by 1
order by 1;
So, what you have to do to fix this is to unload all of your data from that
server, modify TBLTBLFIRST and TBLTBLNEXT in the ONCONFIG file, drop and
recreate all of your dbspaces specifying appropriate extent sizing, and
reload the data. Alternatively you could create new dbspaces with
appropriate extent sizing and use ALTER FRAGMENT FOR TABLE <tabname> INIT...
to move each table to one of the new dbspaces then drop the old ones once
they are empty. However, this latter procedure will not allow you do drop
any dbspaces that contain a database's catalog tables.
Once that is done, the Tablespace Tablespace entries should now be far more
contiguous and the onbar statement will run much faster.
Art
Art S. Kagel
Advanced DataTools (www.advancedatatools.com)
IIUG Board of Directors (art@iiug.org)
Blog: http://informix-myview.blogspot.com/
Disclaimer: Please keep in mind that my own opinions are my own opinions and
do not reflect on my employer, Advanced DataTools, 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 Wed, Feb 23, 2011 at 5:52 PM, Khaled Bentebal <
khaled.bentebal@consult-ix.fr> wrote:
> Hi,
>
> A client of ours is runnning IDS 11.50.FC5 on AIX and is facing a
> problem with a backup running ONBAR.
>
> It runs fine on several instances on different machines, but is very
> slow on one instance. All of the instances are setup the same way along
> the same model and the same ONCONFIG.
>
> ONBAR runs a particular query before performing the backup:
> *select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
> D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = ? *
>
> This query goes on for ever (*few hours*). We tried to run a query on
> sysptnhdr by itself and sysdbspaces also by itself. It seems that the query
> on
> sysptnhdr is very very slow. The same query runs very fast (instantanious)
> on
> the other instances.
> We tried to rebuild the sysmaster databse, but nothing came out it.
>
> Here is more info on this session: any ideas ?
> -------------------------------------------------------------------------
> tid tcb rstcb prty status vp-class name
> 2 7000000b162d9f0 0 1 IO Idle 10lio* lio vp 0
> 3 7000000b166a288 0 1 IO Idle 11pio* pio vp 0
> 4 7000000b1692288 0 1 IO Idle 12aio* aio vp 0
> 5 7000000b16ba288 0 1 IO Idle 13msc* msc vp 0
> 6 7000000b16f2528 7000000b0adc028 3 sleeping secs: 1 1cpu main_loop()
> 7 7000000b1638a50 0 1 running 14soc* soctcppoll
> 8 7000000b15236c0 0 2 sleeping forever 1cpu* soctcplst
> 9 7000000b1692830 0 2 sleeping forever 3cpu* soctcplst
> 10 7000000b16ba4e8 7000000b0adc858 1 sleeping secs: 1 1cpu flush_sub(0)
> 11 7000000b16ba7c0 7000000b0add088 1 sleeping secs: 1 1cpu flush_sub(1)
> 12 7000000b16baa98 7000000b0add8b8 1 sleeping secs: 1 1cpu flush_sub(2)
> 13 7000000b16bad70 7000000b0ade0e8 1 sleeping secs: 1 1cpu flush_sub(3)
> 14 7000000b1617300 0 3 running 3cpu* kaio
> 31 7000000b196a808 0 3 IO Idle 1cpu* kaio
> 37 7000000b1a7a388 7000000b0ade918 2 sleeping secs: 1 1cpu aslogflush
> 38 7000000b1a7a660 7000000b0adf148 1 sleeping secs: 125 1cpu btscanner_0
> 60 7000000b211c928 7000000b0ae09d8 3 sleeping secs: 1 1cpu* onmode_mon
> 61 7000000b211cb88 7000000b0ae01a8 3 sleeping secs: 1 1cpu periodic
> 62 7000000b257e028 0 3 IO Idle 4cpu* kaio
> 67 7000000b23ec418 7000000b0ae1a38 1 sleeping secs: 10 1cpu dbScheduler
> 69 7000000b2337028 7000000b0ae1208 1 sleeping forever 3cpu dbWorker1
> 70 7000000b2373568 7000000b0ae2268 1 sleeping forever 1cpu dbWorker2
> 73 7000000b21c5148 0 3 IO Idle 6cpu* kaio
> 76 7000000b21c55e8 0 3 IO Idle 7cpu* kaio
> 77 7000000b21c5ad8 7000000b0adf978 1 cond wait bp_cond 1cpu bf_priosweep()
> 78 7000000b22131e8 0 3 IO Idle 5cpu* kaio
> 87 7000000b5fd5550 0 3 IO Idle 9cpu* kaio
> 93 7000000b5fd5bc8 0 3 IO Idle 8cpu* kaio
> * 129 7000000b241a930 7000000b0ae3af8 1 IO Wait 3cpu ontape*
>
> IBM Informix Dynamic Server Version 11.50.FC5 -- On-Line -- Up 02:45:14 --> 3142096 Kbytes
>
> Stack for thread: 129 ontape> base: 0x07000000b603d000
>
> len: 135168
>
> pc: 0x00000001000429b0
>
> tos: 0x07000000b605a3b0
> state: sleeping
>
> vp: 3
>
> 0x00000001000429b0 (oninit)yield_processor_mvp
> 0x000000010004d400 (oninit)mt_yield
> 0x00000001000d1798 (oninit)mt_aio_wait
> 0x00000001000d1cb0 (oninit)mt_aio_start
> 0x00000001001e8268 (oninit)chunkio_int
> 0x00000001001e5ea8 (oninit)chunkio
> 0x00000001001ea52c (oninit)physio
> 0x00000001001ef024 (oninit)buffget
> 0x00000001001978c0 (oninit)pthdrgetx
> 0x000000010019cf80 (oninit)ptalloc
> 0x0000000100348664 (oninit)nxtpartp
> 0x0000000100345898 (oninit)prptnhdr
> 0x000000010033e064 (oninit)pstread
> 0x0000000100327288 (oninit)pst_rsread
> 0x00000001003306e8 (oninit)rsread
> 0x00000001004500fc (oninit)fmread
> 0x00000001007e811c (oninit)readseq
> 0x00000001007e883c (oninit)gettupl
> 0x00000001007ebc78 (oninit)scan_next
> 0x000000010089d57c (oninit)hjoin_open
> 0x0000000100bf41d0 (oninit)group_open
Thanks Art,
I did suspect the tablespace tablespace. It is true that there are a lot
of dbspaces (around 150 dbspaces). This is historical.
Since it is in production and the sizes are large, we will try to
reorganize the appropriate dbspaces to shorten the downtime.
The client did not set TBLTBLFIRST and TBLTBLNEXT since he migrated from
V9.40 without changing much to be able to have the same behavior.
Clients do not always follow what you advise. They also have their
procedures. They do not like changing things without going through an
extensive set of tests and validations. This time they did not have the
time to perform all of the tests since they had to move out of 9.40
because of support issues.
We will give it a try.
Khaled Bentebal
Email: khaled.bentebal@consult-ix.fr
Le 24/02/11 01:05, Art Kagel a écrit :
> I suspect that sysmaster isn't the problem, it is that your Tablespace
> Tablespaces have too many extents. This can happen if you have lots
> of dbspaces and a large number of tables, indexes, and fragments of
> tables and indexes spread across them.
>
> Every table in the system has a partition header page, also known as
> its Tablespace Tablespace page. The descriptive and performance
> profile data from these header pages are what are displayed by the
> sysmaster pseudo tables sysptnhdr and sysactptnhdr (the former is just
> an older version of the later included for backward compatibility).
> The Tablespace Tablespace is treated as a table by the server with a
> partition in each dbspace which holds the partition header pages for
> all tables, indexes, and fragments of tables and indexes that are
> resident in that dbspace. What has happened is that when you
> creating your tables and indexes the Tablespace Tablespace became
> fragmented within each dbspace. Since this is not an 'actual' table,
> it has no indexes, so searching it, as onbar does with the query you
> posted, requires a sequential scan of all of those fragmented
> extents. By default, the initial and next extent sizes for the
> Tablespace Tablespace for the root chunk are 250 K and 4 K
> respectively. Other dbspaces default to even lower values: 50 pages
> (using the dbspace's pagesize) and 4 pages unless you modified those
> values with the onspaces -ef and -en options when you created the
> dbspaces. There are now two ONCONFIG parameters, TBLTBLFIRST and
> TBLTBLNEXT, that control the initial extent sizing for this structure
> in the root dbspace, however, it is only effective for the root
> dbspace when the server is initialized.
>
> You can determine how big these parameters need to be set to for each
> dbspace by using the following select:
>
> select dbsname, count(*) as num_extents, sum( size * pagesize / 1024)> as total_kb
> from sysextents se, sysdbspaces sd
> where se.tabname matches 'TBL*'
> and se.dbsname = sd.name <http://sd.name>;
> group by 1
> order by 1;
>
> So, what you have to do to fix this is to unload all of your data from
> that server, modify TBLTBLFIRST and TBLTBLNEXT in the ONCONFIG file,
> drop and recreate all of your dbspaces specifying appropriate extent
> sizing, and reload the data. Alternatively you could create new
> dbspaces with appropriate extent sizing and use ALTER FRAGMENT FOR
> TABLE <tabname> INIT... to move each table to one of the new dbspaces
> then drop the old ones once they are empty. However, this latter
> procedure will not allow you do drop any dbspaces that contain a
> database's catalog tables.
>
> Once that is done, the Tablespace Tablespace entries should now be far
> more contiguous and the onbar statement will run much faster.
>
> Art
>
> Art S. Kagel
> Advanced DataTools (www.advancedatatools.com
> <http://www.advancedatatools.com>)
> IIUG Board of Directors (art@iiug.org <mailto:art@iiug.org>)
> Blog: http://informix-myview.blogspot.com/
>
> Disclaimer: Please keep in mind that my own opinions are my own
> opinions and do not reflect on my employer, Advanced DataTools, 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 Wed, Feb 23, 2011 at 5:52 PM, Khaled Bentebal
> <khaled.bentebal@consult-ix.fr <mailto:khaled.bentebal@consult-ix.fr>>
> wrote:
>
> Hi,
>
> A client of ours is runnning IDS 11.50.FC5 on AIX and is facing a
> problem with a backup running ONBAR.
>
> It runs fine on several instances on different machines, but is very
> slow on one instance. All of the instances are setup the same way
> along
> the same model and the same ONCONFIG.
>
> ONBAR runs a particular query before performing the backup:
> *select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P
> where
> D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = ? *
>
> This query goes on for ever (*few hours*). We tried to run a query on
> sysptnhdr by itself and sysdbspaces also by itself. It seems that
> the query on
> sysptnhdr is very very slow. The same query runs very fast
> (instantanious) on
> the other instances.
> We tried to rebuild the sysmaster databse, but nothing came out it.
>
> Here is more info on this session: any ideas ?
> -------------------------------------------------------------------------
> tid tcb rstcb prty status vp-class name
> 2 7000000b162d9f0 0 1 IO Idle 10lio* lio vp 0
> 3 7000000b166a288 0 1 IO Idle 11pio* pio vp 0
> 4 7000000b1692288 0 1 IO Idle 12aio* aio vp 0
> 5 7000000b16ba288 0 1 IO Idle 13msc* msc vp 0
> 6 7000000b16f2528 7000000b0adc028 3 sleeping secs: 1 1cpu main_loop()
> 7 7000000b1638a50 0 1 running 14soc* soctcppoll
> 8 7000000b15236c0 0 2 sleeping forever 1cpu* soctcplst
> 9 7000000b1692830 0 2 sleeping forever 3cpu* soctcplst
> 10 7000000b16ba4e8 7000000b0adc858 1 sleeping secs: 1 1cpu
> flush_sub(0)
> 11 7000000b16ba7c0 7000000b0add088 1 sleeping secs: 1 1cpu
> flush_sub(1)
> 12 7000000b16baa98 7000000b0add8b8 1 sleeping secs: 1 1cpu
> flush_sub(2)
> 13 7000000b16bad70 7000000b0ade0e8 1 sleeping secs: 1 1cpu
> flush_sub(3)
> 14 7000000b1617300 0 3 running 3cpu* kaio
> 31 7000000b196a808 0 3 IO Idle 1cpu* kaio
> 37 7000000b1a7a388 7000000b0ade918 2 sleeping secs: 1 1cpu aslogflush
> 38 7000000b1a7a660 7000000b0adf148 1 sleeping secs: 125 1cpu
> btscanner_0
> 60 7000000b211c928 7000000b0ae09d8 3 sleeping secs: 1 1cpu* onmode_mon
> 61 7000000b211cb88 7000000b0ae01a8 3 sleeping secs: 1 1cpu periodic
> 62 7000000b257e028 0 3 IO Idle 4cpu* kaio
> 67 7000000b23ec418 7000000b0ae1a38 1 sleeping secs: 10 1cpu
> dbScheduler
> 69 7000000b2337028 7000000b0ae1208 1 sleeping forever 3cpu dbWorker1
> 70 7000000b2373568 7000000b0ae2268 1 sleeping forever 1cpu dbWorker2
> 73 7000000b21c5148 0 3 IO Idle 6cpu* kaio
> 76 7000000b21c55e8 0 3 IO Idle 7cpu* kaio
> 77 7000000b21c5ad8 7000000b0adf978 1 cond wait bp_cond 1cpu
> bf_priosweep()
> 78 7000000b22131e8 0 3 IO Idle 5cpu* kaio
> 87 7000000b5fd5550 0 3 IO Idle 9cpu* kaio
> 93 7000000b5fd5bc8 0 3 IO Idle 8cpu* kaio
> * 129 7000000b241a930 7000000b0ae3af8
Thanks Fernando,
What about APAR IC67929 ? This has been also mentionned by support as a
possibility.
A PMR has been opened.
Khaled Bentebal
Email: khaled.bentebal@consult-ix.fr
Le 24/02/11 00:13, Fernando Nunes a écrit :
> Hello,
>
> It looks like APAR IC71702
>
> https://www-304.ibm.com/support/entdocview.wss?uid=swg1IC71702
>
> It's fixed in 11.50.FC8W2
> You may want to open a PMR for further details.
>
> Check that the "slow" instance has much more partitions (either table,
> indexes or fragments) than the other(s).
>
> Regards.
>
> On Wed, Feb 23, 2011 at 10:52 PM, Khaled Bentebal<
> khaled.bentebal@consult-ix.fr> wrote:
>
>> Hi,
>>
>> A client of ours is runnning IDS 11.50.FC5 on AIX and is facing a
>> problem with a backup running ONBAR.
>>
>> It runs fine on several instances on different machines, but is very
>> slow on one instance. All of the instances are setup the same way along
>> the same model and the same ONCONFIG.
>>
>> ONBAR runs a particular query before performing the backup:
>> *select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
>> D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = ? *
>>
>> This query goes on for ever (*few hours*). We tried to run a query on
>> sysptnhdr by itself and sysdbspaces also by itself. It seems that the query
>> on
>> sysptnhdr is very very slow. The same query runs very fast (instantanious)
>> on
>> the other instances.
>> We tried to rebuild the sysmaster databse, but nothing came out it.
>>
>> Here is more info on this session: any ideas ?
>> -------------------------------------------------------------------------
>> tid tcb rstcb prty status vp-class name
>> 2 7000000b162d9f0 0 1 IO Idle 10lio* lio vp 0
>> 3 7000000b166a288 0 1 IO Idle 11pio* pio vp 0
>> 4 7000000b1692288 0 1 IO Idle 12aio* aio vp 0
>> 5 7000000b16ba288 0 1 IO Idle 13msc* msc vp 0
>> 6 7000000b16f2528 7000000b0adc028 3 sleeping secs: 1 1cpu main_loop()
>> 7 7000000b1638a50 0 1 running 14soc* soctcppoll
>> 8 7000000b15236c0 0 2 sleeping forever 1cpu* soctcplst
>> 9 7000000b1692830 0 2 sleeping forever 3cpu* soctcplst
>> 10 7000000b16ba4e8 7000000b0adc858 1 sleeping secs: 1 1cpu flush_sub(0)
>> 11 7000000b16ba7c0 7000000b0add088 1 sleeping secs: 1 1cpu flush_sub(1)
>> 12 7000000b16baa98 7000000b0add8b8 1 sleeping secs: 1 1cpu flush_sub(2)
>> 13 7000000b16bad70 7000000b0ade0e8 1 sleeping secs: 1 1cpu flush_sub(3)
>> 14 7000000b1617300 0 3 running 3cpu* kaio
>> 31 7000000b196a808 0 3 IO Idle 1cpu* kaio
>> 37 7000000b1a7a388 7000000b0ade918 2 sleeping secs: 1 1cpu aslogflush
>> 38 7000000b1a7a660 7000000b0adf148 1 sleeping secs: 125 1cpu btscanner_0
>> 60 7000000b211c928 7000000b0ae09d8 3 sleeping secs: 1 1cpu* onmode_mon
>> 61 7000000b211cb88 7000000b0ae01a8 3 sleeping secs: 1 1cpu periodic
>> 62 7000000b257e028 0 3 IO Idle 4cpu* kaio
>> 67 7000000b23ec418 7000000b0ae1a38 1 sleeping secs: 10 1cpu dbScheduler
>> 69 7000000b2337028 7000000b0ae1208 1 sleeping forever 3cpu dbWorker1
>> 70 7000000b2373568 7000000b0ae2268 1 sleeping forever 1cpu dbWorker2
>> 73 7000000b21c5148 0 3 IO Idle 6cpu* kaio
>> 76 7000000b21c55e8 0 3 IO Idle 7cpu* kaio
>> 77 7000000b21c5ad8 7000000b0adf978 1 cond wait bp_cond 1cpu bf_priosweep()
>> 78 7000000b22131e8 0 3 IO Idle 5cpu* kaio
>> 87 7000000b5fd5550 0 3 IO Idle 9cpu* kaio
>> 93 7000000b5fd5bc8 0 3 IO Idle 8cpu* kaio
>> * 129 7000000b241a930 7000000b0ae3af8 1 IO Wait 3cpu ontape*
>>
>> IBM Informix Dynamic Server Version 11.50.FC5 -- On-Line -- Up 02:45:14 -->> 3142096 Kbytes
>>
>> Stack for thread: 129 ontape>> base: 0x07000000b603d000
>>
>> len: 135168
>>
>> pc: 0x00000001000429b0
>>
>> tos: 0x07000000b605a3b0
>> state: sleeping
>>
>> vp: 3
>>
>> 0x00000001000429b0 (oninit)yield_processor_mvp
>> 0x000000010004d400 (oninit)mt_yield
>> 0x00000001000d1798 (oninit)mt_aio_wait
>> 0x00000001000d1cb0 (oninit)mt_aio_start
>> 0x00000001001e8268 (oninit)chunkio_int
>> 0x00000001001e5ea8 (oninit)chunkio
>> 0x00000001001ea52c (oninit)physio
>> 0x00000001001ef024 (oninit)buffget
>> 0x00000001001978c0 (oninit)pthdrgetx
>> 0x000000010019cf80 (oninit)ptalloc
>> 0x0000000100348664 (oninit)nxtpartp
>> 0x0000000100345898 (oninit)prptnhdr
>> 0x000000010033e064 (oninit)pstread
>> 0x0000000100327288 (oninit)pst_rsread
>> 0x00000001003306e8 (oninit)rsread
>> 0x00000001004500fc (oninit)fmread
>> 0x00000001007e811c (oninit)readseq
>> 0x00000001007e883c (oninit)gettupl
>> 0x00000001007ebc78 (oninit)scan_next
>> 0x000000010089d57c (oninit)hjoin_open
>> 0x0000000100bf41d0 (oninit)group_open
>> 0x0000000100551718 (oninit)prepselect
>> 0x0000000100458130 (oninit)excommand
>> 0x000000010041c464 (oninit)sq_exselect
>> 0x00000001002187a0 (oninit)sqmain
>> 0x0000000100578b50 (oninit)listen_verify
>> 0x0000000100577294 (oninit)spawn_thread
>> 0x0000000100d0f93c (oninit)startup
>>
>> tid name rstcb flags curstk status
>> 129 ontape 7000000b0ae3af8 Y--PR-M 12720 cond wait pt_448a8d -
>>
>> Memory pools count 2
>> name class addr totalsize freesize #allocfrag #freefrag
>> 92 V 7000000b2307040 229376 19480 293 27
>> 92*O0 V 7000000b5fe9040 4096 808 1 1
>>
>> name free used name free used
>> overhead 0 6576 mtmisc 0 144
>> scb 0 144 opentable 0 7752
>> filetable 0 1936 ru 0 600
>> log 0 16536 temprec 0 2208
>> keys 0 208 ralloc 0 128072
>> gentcb 0 1584 ostcb 0 3400
>> sort 0 104 sqscb 0 21696
>> sql 0 72 hashfiletab 0 552
>> osenv 0 3376 buft_buffer 0 4216
>> sqtcb 0 10760 fragman 0 776
>> shmblklist 0 704 udr 0 1768
>>
>> sqscb info
>> scb sqscb optofc pdqpriority sqlstats optcompind directives
>> 7000000b24e9110 7000000b274c028 0 0 0 0 1
>>
>> Sess SQL Current Iso Lock SQL ISAM F.E.
>> Id Stmt type Database Lvl Mode ERR ERR Vers Explain
>> 92 SELECT sysmaster RR Wait 300 0 0 9.24 Off
>>
>> Current SQL statement :
>>
>> select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where D
>>
>> .. dbsnum = TRUNC ( P . partnum/ 1048576 ) and name = ?
>>
>> Host variables :
>>
>> address type flags value
>>
>> -----------------------------------------
>>
>> 0x07000000b5a2d268 CHAR 0x000 db11_13trnr
>>
>> Last parsed SQL statement :
>>
>> select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where D
>>
>> .. dbsnum = TRUNC ( P . partnum/ 1048576 ) and name = ?
>>
>> mpm13trnr_prodappl(ifx/ifx) /tmp> more sqexplain.out
>>
>> QUERY: (OPTIMIZATION TIMESTAMP: 02-22-2011 13:58:12)
>> ------
>> select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
>> D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = "de07_13trnr"
>>
>> Estimated Cost: 30
>> Estimated # of Rows Returned: 1
>>
>> 1) ifx.d: INDEX PATH
>>
>> Filters: ifx.d.name = 'de07_13trnr'
>>
>> (1) Index Name: informix.sysdbstab_dbsnum
>>
>> Index Keys: dbsnum
>>
>> Lower Index Filter: ifx.d.dbsnum> 0
>>
>> 2) ifx.p: SEQUENTIAL SCAN
>>
>> DYNAMIC HASH JOIN
>>
>> Dynamic Hash Filters: ifx.d.dbsnum = trunc(ifx.p.partnum / 1048576 )
>>@@
I would suggest you try the query below. For large system with lots of
partition pages the problem is the sequential scan on the sysptnhdr table.
The
directives added to the query below should force the use of the index on
the
sysptnhdr table. If this query does perform well you can install the
directives
using the "Save External Directive" statement and fix the issue.
select {+ORDERED, USE_NL(sysptnhdr) } ( sum ( npused ) )
from sysdbspaces as D , sysptnhdr as P
where D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = "rootdbs"
John F. Miller III
STSM, Embedability Architect
miller3@us.ibm.com
503-578-5645
IBM Informix Dynamic Server (IDS)
ids-bounces@iiug.org wrote on 02/23/2011 03:13:36 PM:
> [image removed]
>
> Re: Problem with ONBAR: unusually slow on IDS .... [22885]
>
> Fernando Nunes
>
> to:
>
> ids
>
> 02/23/2011 03:14 PM
>
> Sent by:
>
> ids-bounces@iiug.org
>
> Please respond to ids
>
> Hello,
>
> It looks like APAR IC71702
>
> https://www-304.ibm.com/support/entdocview.wss?uid=swg1IC71702
>
> It's fixed in 11.50.FC8W2
> You may want to open a PMR for further details.
>
> Check that the "slow" instance has much more partitions (either table,
> indexes or fragments) than the other(s).
>
> Regards.
>
> On Wed, Feb 23, 2011 at 10:52 PM, Khaled Bentebal <
> khaled.bentebal@consult-ix.fr> wrote:
>
> > Hi,
> >
> > A client of ours is runnning IDS 11.50.FC5 on AIX and is facing a
> > problem with a backup running ONBAR.
> >
> > It runs fine on several instances on different machines, but is very
> > slow on one instance. All of the instances are setup the same way along
> > the same model and the same ONCONFIG.
> >
> > ONBAR runs a particular query before performing the backup:
> > *select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
> > D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = ? *
> >
> > This query goes on for ever (*few hours*). We tried to run a query on
> > sysptnhdr by itself and sysdbspaces also by itself. It seems that the
query
> > on
> > sysptnhdr is very very slow. The same query runs very fast
(instantanious)
> > on
> > the other instances.
> > We tried to rebuild the sysmaster databse, but nothing came out it.
> >
> > Here is more info on this session: any ideas ?
> >
-------------------------------------------------------------------------
> > tid tcb rstcb prty status vp-class name
> > 2 7000000b162d9f0 0 1 IO Idle 10lio* lio vp 0
> > 3 7000000b166a288 0 1 IO Idle 11pio* pio vp 0
> > 4 7000000b1692288 0 1 IO Idle 12aio* aio vp 0
> > 5 7000000b16ba288 0 1 IO Idle 13msc* msc vp 0
> > 6 7000000b16f2528 7000000b0adc028 3 sleeping secs: 1 1cpu main_loop()
> > 7 7000000b1638a50 0 1 running 14soc* soctcppoll
> > 8 7000000b15236c0 0 2 sleeping forever 1cpu* soctcplst
> > 9 7000000b1692830 0 2 sleeping forever 3cpu* soctcplst
> > 10 7000000b16ba4e8 7000000b0adc858 1 sleeping secs: 1 1cpu flush_sub(0)
> > 11 7000000b16ba7c0 7000000b0add088 1 sleeping secs: 1 1cpu flush_sub(1)
> > 12 7000000b16baa98 7000000b0add8b8 1 sleeping secs: 1 1cpu flush_sub(2)
> > 13 7000000b16bad70 7000000b0ade0e8 1 sleeping secs: 1 1cpu flush_sub(3)
> > 14 7000000b1617300 0 3 running 3cpu* kaio
> > 31 7000000b196a808 0 3 IO Idle 1cpu* kaio
> > 37 7000000b1a7a388 7000000b0ade918 2 sleeping secs: 1 1cpu aslogflush
> > 38 7000000b1a7a660 7000000b0adf148 1 sleeping secs: 125 1cpu
btscanner_0
> > 60 7000000b211c928 7000000b0ae09d8 3 sleeping secs: 1 1cpu* onmode_mon
> > 61 7000000b211cb88 7000000b0ae01a8 3 sleeping secs: 1 1cpu periodic
> > 62 7000000b257e028 0 3 IO Idle 4cpu* kaio
> > 67 7000000b23ec418 7000000b0ae1a38 1 sleeping secs: 10 1cpu dbScheduler
> > 69 7000000b2337028 7000000b0ae1208 1 sleeping forever 3cpu dbWorker1
> > 70 7000000b2373568 7000000b0ae2268 1 sleeping forever 1cpu dbWorker2
> > 73 7000000b21c5148 0 3 IO Idle 6cpu* kaio
> > 76 7000000b21c55e8 0 3 IO Idle 7cpu* kaio
> > 77 7000000b21c5ad8 7000000b0adf978 1 cond wait bp_cond 1cpu
bf_priosweep()
> > 78 7000000b22131e8 0 3 IO Idle 5cpu* kaio
> > 87 7000000b5fd5550 0 3 IO Idle 9cpu* kaio
> > 93 7000000b5fd5bc8 0 3 IO Idle 8cpu* kaio
> > * 129 7000000b241a930 7000000b0ae3af8 1 IO Wait 3cpu ontape*
> >
> > IBM Informix Dynamic Server Version 11.50.FC5 -- On-Line -- Up 02:45:14
--> > 3142096 Kbytes
> >
> > Stack for thread: 129 ontape> > base: 0x07000000b603d000
> >
> > len: 135168
> >
> > pc: 0x00000001000429b0
> >
> > tos: 0x07000000b605a3b0
> > state: sleeping
> >
> > vp: 3
> >
> > 0x00000001000429b0 (oninit)yield_processor_mvp
> > 0x000000010004d400 (oninit)mt_yield
> > 0x00000001000d1798 (oninit)mt_aio_wait
> > 0x00000001000d1cb0 (oninit)mt_aio_start
> > 0x00000001001e8268 (oninit)chunkio_int
> > 0x00000001001e5ea8 (oninit)chunkio
> > 0x00000001001ea52c (oninit)physio
> > 0x00000001001ef024 (oninit)buffget
> > 0x00000001001978c0 (oninit)pthdrgetx
> > 0x000000010019cf80 (oninit)ptalloc
> > 0x0000000100348664 (oninit)nxtpartp
> > 0x0000000100345898 (oninit)prptnhdr
> > 0x000000010033e064 (oninit)pstread
> > 0x0000000100327288 (oninit)pst_rsread
> > 0x00000001003306e8 (oninit)rsread
> > 0x00000001004500fc (oninit)fmread
> > 0x00000001007e811c (oninit)readseq
> > 0x00000001007e883c (oninit)gettupl
> > 0x00000001007ebc78 (oninit)scan_next
> > 0x000000010089d57c (oninit)hjoin_open
> > 0x0000000100bf41d0 (oninit)group_open
> > 0x0000000100551718 (oninit)prepselect
> > 0x0000000100458130 (oninit)excommand
> > 0x000000010041c464 (oninit)sq_exselect
> > 0x00000001002187a0 (oninit)sqmain
> > 0x0000000100578b50 (oninit)listen_verify
> > 0x0000000100577294 (oninit)spawn_thread
> > 0x0000000100d0f93c (oninit)startup
> >
> > tid name rstcb flags curstk status
> > 129 ontape 7000000b0ae3af8 Y--PR-M 12720 cond wait pt_448a8d -
> >
> > Memory pools count 2
> > name class addr totalsize freesize #allocfrag #freefrag
> > 92 V 7000000b2307040 229376 19480 293 27
> > 92*O0 V 7000000b5fe9040 4096 808 1 1
> >
> > name free used name free used
> > overhead 0 6576 mtmisc 0 144
> > scb 0 144 opentable 0 7752
> > filetable 0 1936 ru 0 600
> > log 0 16536 temprec 0 2208
> > keys 0 208 ralloc 0 128072
> > gentcb 0 1584 ostcb 0 3400
> > sort 0 104 sqscb 0 21696
> > sql 0 72 hashfiletab 0 552
> > osenv 0 3376 buft_buffer 0 4216
> > sqtcb 0 10760 fragman 0 776
> > shmblklist 0 704 udr 0 1768
> >
> > sqscb info
> > scb sqscb optofc pdqpriority sqlstats optcompind directives
> > 7000000b24e9110 7000000b274c028 0 0 0 0 1
> >
> > Sess SQL Current Iso Lock SQL ISAM F.E.
> > Id Stmt type Database Lvl Mode ERR ERR Vers Explain
> > 92 SELECT sysmaster RR Wait 300 0 0 9.24 Off
> >
> > Current SQL statement :
> >
> > select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
D
> >
> > .. dbsnum = TRUNC ( P . partnum/ 1048576 ) and name = ?
> >
> > Host variables :
> >
> > address type flags value
> >
> > ------------------------------
Khaled,
I met this bug in Nov 2010. In my environment, this query used to take more
than 24 hours to start transfer data to tape. I upgraded to 11.50.FC8 and
solved the problem.
https://www-304.ibm.com/support/docview.wss?uid=swg1IC67929
Celso Cabral Coimbra
Administrador de Banco de Dados
ClearTech Ltda
"Trust at the heart of Communications"
Tel. (11) 3576-4509
-----Mensagem original-----
De: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] Em nome de Khaled
Bentebal
Enviada em: quarta-feira, 23 de fevereiro de 2011 22:51
Para: ids@iiug.org
Assunto: Re: Problem with ONBAR: unusually slow on IDS .... [22894]
Thanks Fernando,
What about APAR IC67929 ? This has been also mentionned by support as a
possibility.
A PMR has been opened.
Khaled Bentebal
Email: khaled.bentebal@consult-ix.fr
Le 24/02/11 00:13, Fernando Nunes a écrit :
> Hello,
>
> It looks like APAR IC71702
>
> https://www-304.ibm.com/support/entdocview.wss?uid=swg1IC71702
>
> It's fixed in 11.50.FC8W2
> You may want to open a PMR for further details.
>
> Check that the "slow" instance has much more partitions (either table,
> indexes or fragments) than the other(s).
>
> Regards.
>
> On Wed, Feb 23, 2011 at 10:52 PM, Khaled Bentebal<
> khaled.bentebal@consult-ix.fr> wrote:
>
>> Hi,
>>
>> A client of ours is runnning IDS 11.50.FC5 on AIX and is facing a
>> problem with a backup running ONBAR.
>>
>> It runs fine on several instances on different machines, but is very
>> slow on one instance. All of the instances are setup the same way along
>> the same model and the same ONCONFIG.
>>
>> ONBAR runs a particular query before performing the backup:
>> *select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
>> D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = ? *
>>
>> This query goes on for ever (*few hours*). We tried to run a query on
>> sysptnhdr by itself and sysdbspaces also by itself. It seems that the query
>> on
>> sysptnhdr is very very slow. The same query runs very fast (instantanious)
>> on
>> the other instances.
>> We tried to rebuild the sysmaster databse, but nothing came out it.
>>
>> Here is more info on this session: any ideas ?
>> -------------------------------------------------------------------------
>> tid tcb rstcb prty status vp-class name
>> 2 7000000b162d9f0 0 1 IO Idle 10lio* lio vp 0
>> 3 7000000b166a288 0 1 IO Idle 11pio* pio vp 0
>> 4 7000000b1692288 0 1 IO Idle 12aio* aio vp 0
>> 5 7000000b16ba288 0 1 IO Idle 13msc* msc vp 0
>> 6 7000000b16f2528 7000000b0adc028 3 sleeping secs: 1 1cpu main_loop()
>> 7 7000000b1638a50 0 1 running 14soc* soctcppoll
>> 8 7000000b15236c0 0 2 sleeping forever 1cpu* soctcplst
>> 9 7000000b1692830 0 2 sleeping forever 3cpu* soctcplst
>> 10 7000000b16ba4e8 7000000b0adc858 1 sleeping secs: 1 1cpu flush_sub(0)
>> 11 7000000b16ba7c0 7000000b0add088 1 sleeping secs: 1 1cpu flush_sub(1)
>> 12 7000000b16baa98 7000000b0add8b8 1 sleeping secs: 1 1cpu flush_sub(2)
>> 13 7000000b16bad70 7000000b0ade0e8 1 sleeping secs: 1 1cpu flush_sub(3)
>> 14 7000000b1617300 0 3 running 3cpu* kaio
>> 31 7000000b196a808 0 3 IO Idle 1cpu* kaio
>> 37 7000000b1a7a388 7000000b0ade918 2 sleeping secs: 1 1cpu aslogflush
>> 38 7000000b1a7a660 7000000b0adf148 1 sleeping secs: 125 1cpu btscanner_0
>> 60 7000000b211c928 7000000b0ae09d8 3 sleeping secs: 1 1cpu* onmode_mon
>> 61 7000000b211cb88 7000000b0ae01a8 3 sleeping secs: 1 1cpu periodic
>> 62 7000000b257e028 0 3 IO Idle 4cpu* kaio
>> 67 7000000b23ec418 7000000b0ae1a38 1 sleeping secs: 10 1cpu dbScheduler
>> 69 7000000b2337028 7000000b0ae1208 1 sleeping forever 3cpu dbWorker1
>> 70 7000000b2373568 7000000b0ae2268 1 sleeping forever 1cpu dbWorker2
>> 73 7000000b21c5148 0 3 IO Idle 6cpu* kaio
>> 76 7000000b21c55e8 0 3 IO Idle 7cpu* kaio
>> 77 7000000b21c5ad8 7000000b0adf978 1 cond wait bp_cond 1cpu bf_priosweep()
>> 78 7000000b22131e8 0 3 IO Idle 5cpu* kaio
>> 87 7000000b5fd5550 0 3 IO Idle 9cpu* kaio
>> 93 7000000b5fd5bc8 0 3 IO Idle 8cpu* kaio
>> * 129 7000000b241a930 7000000b0ae3af8 1 IO Wait 3cpu ontape*
>>
>> IBM Informix Dynamic Server Version 11.50.FC5 -- On-Line -- Up 02:45:14 -->> 3142096 Kbytes
>>
>> Stack for thread: 129 ontape>> base: 0x07000000b603d000
>>
>> len: 135168
>>
>> pc: 0x00000001000429b0
>>
>> tos: 0x07000000b605a3b0
>> state: sleeping
>>
>> vp: 3
>>
>> 0x00000001000429b0 (oninit)yield_processor_mvp
>> 0x000000010004d400 (oninit)mt_yield
>> 0x00000001000d1798 (oninit)mt_aio_wait
>> 0x00000001000d1cb0 (oninit)mt_aio_start
>> 0x00000001001e8268 (oninit)chunkio_int
>> 0x00000001001e5ea8 (oninit)chunkio
>> 0x00000001001ea52c (oninit)physio
>> 0x00000001001ef024 (oninit)buffget
>> 0x00000001001978c0 (oninit)pthdrgetx
>> 0x000000010019cf80 (oninit)ptalloc
>> 0x0000000100348664 (oninit)nxtpartp
>> 0x0000000100345898 (oninit)prptnhdr
>> 0x000000010033e064 (oninit)pstread
>> 0x0000000100327288 (oninit)pst_rsread
>> 0x00000001003306e8 (oninit)rsread
>> 0x00000001004500fc (oninit)fmread
>> 0x00000001007e811c (oninit)readseq
>> 0x00000001007e883c (oninit)gettupl
>> 0x00000001007ebc78 (oninit)scan_next
>> 0x000000010089d57c (oninit)hjoin_open
>> 0x0000000100bf41d0 (oninit)group_open
>> 0x0000000100551718 (oninit)prepselect
>> 0x0000000100458130 (oninit)excommand
>> 0x000000010041c464 (oninit)sq_exselect
>> 0x00000001002187a0 (oninit)sqmain
>> 0x0000000100578b50 (oninit)listen_verify
>> 0x0000000100577294 (oninit)spawn_thread
>> 0x0000000100d0f93c (oninit)startup
>>
>> tid name rstcb flags curstk status
>> 129 ontape 7000000b0ae3af8 Y--PR-M 12720 cond wait pt_448a8d -
>>
>> Memory pools count 2
>> name class addr totalsize freesize #allocfrag #freefrag
>> 92 V 7000000b2307040 229376 19480 293 27
>> 92*O0 V 7000000b5fe9040 4096 808 1 1
>>
>> name free used name free used
>> overhead 0 6576 mtmisc 0 144
>> scb 0 144 opentable 0 7752
>> filetable 0 1936 ru 0 600
>> log 0 16536 temprec 0 2208
>> keys 0 208 ralloc 0 128072
>> gentcb 0 1584 ostcb 0 3400
>> sort 0 104 sqscb 0 21696
>> sql 0 72 hashfiletab 0 552
>> osenv 0 3376 buft_buffer 0 4216
>> sqtcb 0 10760 fragman 0 776
>> shmblklist 0 704 udr 0 1768
>>
>> sqscb info
>> scb sqscb optofc pdqpriority sqlstats optcompind directives
>> 7000000b24e9110 7000000b274c028 0 0 0 0 1
>>
>> Sess SQL Current Iso Lock SQL ISAM F.E.
>> Id Stmt type Database Lvl Mode ERR ERR Vers Explain
>> 92 SELECT sysmaster RR Wait 300 0 0 9.24 Off
>>
>> Current SQL statement :
>>
>> select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where D
>>
>> .. dbsnum = TRUNC ( P . partnum/ 1048576 ) and name = ?
>>
>> Host variables :
>>
>> address type flags value
>>
>> -----------------------------------------
>>
>> 0x07000000b5a2d268 CHAR 0x000 db11_13trnr
>>
>> Last parsed SQL statement :
>>
>> select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where D
>>
>> .. dbsnum = TRUNC ( P . partnum/ 1048576 ) and name = ?
>>
>> mpm13trnr_prodappl(ifx/ifx) /tmp> more
As far as I can tell it looks the same defect.... But to be honest the
information is a bit confusing for me (I'm not a usual client of the
internal tools).
Technical support will be able to provide a clear explanation. Please
mention the two APARs.
There are some references that lead me to think that this was resolved in
several internal bug references (one for specific spaces - blobs -, other
related to DBSPACE ordering etc.)
But in any case, it all looks fixed in FC8W2 or maybe in FC8, so you may
need to consider an upgrade.
Note that between FC5 and FC8 there will be conversion.... Meaning that if
you want to go back it's not simply a matter of shutting down FC8* and
starting FC5.
This is nothing too special, but as usual, test, test, test.... :)
On Thu, Feb 24, 2011 at 1:50 AM, Khaled Bentebal <
khaled.bentebal@consult-ix.fr> wrote:
> Thanks Fernando,
>
> What about APAR IC67929 ? This has been also mentionned by support as a
> possibility.
>
> A PMR has been opened.
>
> Khaled Bentebal
>
> Email: khaled.bentebal@consult-ix.fr
>
> Le 24/02/11 00:13, Fernando Nunes a écrit :
> > Hello,
> >
> > It looks like APAR IC71702
> >
> > https://www-304.ibm.com/support/entdocview.wss?uid=swg1IC71702
> >
> > It's fixed in 11.50.FC8W2
> > You may want to open a PMR for further details.
> >
> > Check that the "slow" instance has much more partitions (either table,
> > indexes or fragments) than the other(s).
> >
> > Regards.
> >
> > On Wed, Feb 23, 2011 at 10:52 PM, Khaled Bentebal<
> > khaled.bentebal@consult-ix.fr> wrote:
> >
> >> Hi,
> >>
> >> A client of ours is runnning IDS 11.50.FC5 on AIX and is facing a
> >> problem with a backup running ONBAR.
> >>
> >> It runs fine on several instances on different machines, but is very
> >> slow on one instance. All of the instances are setup the same way along
> >> the same model and the same ONCONFIG.
> >>
> >> ONBAR runs a particular query before performing the backup:
> >> *select ( sum ( npused ) ) from sysdbspaces as D , sysptnhdr as P where
> >> D.dbsnum = TRUNC ( P.partnum/1048576 ) and name = ? *
> >>
> >> This query goes on for ever (*few hours*). We tried to run a query on
> >> sysptnhdr by itself and sysdbspaces also by itself. It seems that the
> query
> >> on
> >> sysptnhdr is very very slow. The same query runs very fast
> (instantanious)
> >> on
> >> the other instances.
> >> We tried to rebuild the sysmaster databse, but nothing came out it.
> >>
> >> Here is more info on this session: any ideas ?
> >>
> -------------------------------------------------------------------------
> >> tid tcb rstcb prty status vp-class name
> >> 2 7000000b162d9f0 0 1 IO Idle 10lio* lio vp 0
> >> 3 7000000b166a288 0 1 IO Idle 11pio* pio vp 0
> >> 4 7000000b1692288 0 1 IO Idle 12aio* aio vp 0
> >> 5 7000000b16ba288 0 1 IO Idle 13msc* msc vp 0
> >> 6 7000000b16f2528 7000000b0adc028 3 sleeping secs: 1 1cpu main_loop()
> >> 7 7000000b1638a50 0 1 running 14soc* soctcppoll
> >> 8 7000000b15236c0 0 2 sleeping forever 1cpu* soctcplst
> >> 9 7000000b1692830 0 2 sleeping forever 3cpu* soctcplst
> >> 10 7000000b16ba4e8 7000000b0adc858 1 sleeping secs: 1 1cpu flush_sub(0)
> >> 11 7000000b16ba7c0 7000000b0add088 1 sleeping secs: 1 1cpu flush_sub(1)
> >> 12 7000000b16baa98 7000000b0add8b8 1 sleeping secs: 1 1cpu flush_sub(2)
> >> 13 7000000b16bad70 7000000b0ade0e8 1 sleeping secs: 1 1cpu flush_sub(3)
> >> 14 7000000b1617300 0 3 running 3cpu* kaio
> >> 31 7000000b196a808 0 3 IO Idle 1cpu* kaio
> >> 37 7000000b1a7a388 7000000b0ade918 2 sleeping secs: 1 1cpu aslogflush
> >> 38 7000000b1a7a660 7000000b0adf148 1 sleeping secs: 125 1cpu btscanner_0
> >> 60 7000000b211c928 7000000b0ae09d8 3 sleeping secs: 1 1cpu* onmode_mon
> >> 61 7000000b211cb88 7000000b0ae01a8 3 sleeping secs: 1 1cpu periodic
> >> 62 7000000b257e028 0 3 IO Idle 4cpu* kaio
> >> 67 7000000b23ec418 7000000b0ae1a38 1 sleeping secs: 10 1cpu dbScheduler
> >> 69 7000000b2337028 7000000b0ae1208 1 sleeping forever 3cpu dbWorker1
> >> 70 7000000b2373568 7000000b0ae2268 1 sleeping forever 1cpu dbWorker2
> >> 73 7000000b21c5148 0 3 IO Idle 6cpu* kaio
> >> 76 7000000b21c55e8 0 3 IO Idle 7cpu* kaio
> >> 77 7000000b21c5ad8 7000000b0adf978 1 cond wait bp_cond 1cpu
> bf_priosweep()
> >> 78 7000000b22131e8 0 3 IO Idle 5cpu* kaio
> >> 87 7000000b5fd5550 0 3 IO Idle 9cpu* kaio
> >> 93 7000000b5fd5bc8 0 3 IO Idle 8cpu* kaio
> >> * 129 7000000b241a930 7000000b0ae3af8 1 IO Wait 3cpu ontape*
> >>
> >> IBM Informix Dynamic Server Version 11.50.FC5 -- On-Line -- Up 02:45:14
> --> >> 3142096 Kbytes
> >>
> >> Stack for thread: 129 ontape> >> base: 0x07000000b603d000
> >>
> >> len: 135168
> >>
> >> pc: 0x00000001000429b0
> >>
> >> tos: 0x07000000b605a3b0
> >> state: sleeping
> >>
> >> vp: 3
> >>
> >> 0x00000001000429b0 (oninit)yield_processor_mvp
> >> 0x000000010004d400 (oninit)mt_yield
> >> 0x00000001000d1798 (oninit)mt_aio_wait
> >> 0x00000001000d1cb0 (oninit)mt_aio_start
> >> 0x00000001001e8268 (oninit)chunkio_int
> >> 0x00000001001e5ea8 (oninit)chunkio
> >> 0x00000001001ea52c (oninit)physio
> >> 0x00000001001ef024 (oninit)buffget
> >> 0x00000001001978c0 (oninit)pthdrgetx
> >> 0x000000010019cf80 (oninit)ptalloc
> >> 0x0000000100348664 (oninit)nxtpartp
> >> 0x0000000100345898 (oninit)prptnhdr
> >> 0x000000010033e064 (oninit)pstread
> >> 0x0000000100327288 (oninit)pst_rsread
> >> 0x00000001003306e8 (oninit)rsread
> >> 0x00000001004500fc (oninit)fmread
> >> 0x00000001007e811c (oninit)readseq
> >> 0x00000001007e883c (oninit)gettupl
> >> 0x00000001007ebc78 (oninit)scan_next
> >> 0x000000010089d57c (oninit)hjoin_open
> >> 0x0000000100bf41d0 (oninit)group_open
> >> 0x0000000100551718 (oninit)prepselect
> >> 0x0000000100458130 (oninit)excommand
> >> 0x000000010041c464 (oninit)sq_exselect
> >> 0x00000001002187a0 (oninit)sqmain
> >> 0x0000000100578b50 (oninit)listen_verify
> >> 0x0000000100577294 (oninit)spawn_thread
> >> 0x0000000100d0f93c (oninit)startup
> >>
> >> tid name rstcb flags curstk status
> >> 129 ontape 7000000b0ae3af8 Y--PR-M 12720 cond wait pt_448a8d -
> >>
> >> Memory pools count 2
> >> name class addr totalsize freesize #allocfrag #freefrag
> >> 92 V 7000000b2307040 229376 19480 293 27
> >> 92*O0 V 7000000b5fe9040 4096 808 1 1
> >>
> >> name free used name free used
> >> overhead 0 6576 mtmisc 0 144
> >> scb 0 144 opentable 0 7752
> >> filetable 0 1936 ru 0 600
> >> log 0 16536 temprec 0 2208
> >> keys 0 208 ralloc 0 128072
> >> gentcb 0 1584 ostcb 0 3400
> >> sort 0 104 sqscb 0 21696
> >> sql 0 72 hashfiletab 0 552
> >> osenv 0 3376 buft_buffer 0 4216
> >> sqtcb 0 10760 fragman 0 776
> >> shmblklist 0 704 udr 0 1768
> >>
> >> sqscb info
> >> scb sqscb optofc pdqpriority sqlstats optcompind directives
> >> 7000000b24e9110 7000000b274c028 0 0 0 0 1
> >>
> >> Sess SQL Current Iso Lock SQL ISAM F.E.
> >> Id Stmt type Database Lvl Mode ERR ERR Vers Explain
> >> 92 SELECT sysmaster RR Wait 300 0 0 9.24 Off
> >>
> >> Current SQL statement :
> >>
> >> select ( sum ( npused ) ) from sysdbspaces