Good point in that link Ben. Similar issue: if you compile stored procedures/functions (UPDATE STATISTICS FOR PROCDURE ...) with non-zero PDQPRIORITY those procedures/functions will always run with that PDQPRIORITY even if the session that calls it has PDQPRIORITY set to zero which can trigger the same behavior described in your link.
Art S. Kagel, President and Principal Consultant
ASK Database Management Corp.
Original Message:
Sent: Thu June 15, 2023 09:26 AM
From: Benjamin Thompson
Subject: PDQ - Why does its performance suck sooooo bad?
Stumbled across this which probably doesn't add much new to the discussion but is an official doc.:
https://www.ibm.com/support/pages/several-scan-threads-cond-wait-awaitmcx-causing-performance-bottlenecks
------------------------------
Benjamin Thompson
Original Message:
Sent: Wed June 07, 2023 02:45 PM
From: Jared Heath
Subject: PDQ - Why does its performance suck sooooo bad?
I have PDQPRIORITY on the server set at 40, 10 on the client, and max set to 50 in the onconfig.
------------------------------
Jared Heath
Original Message:
Sent: Wed June 07, 2023 04:41 AM
From: Benjamin Thompson
Subject: PDQ - Why does its performance suck sooooo bad?
PDQ is definitely there in both Art:
(Parallel, fragments: ALL)
Here is a diff of the two, no differences except in the durations.
< QUERY: (OPTIMIZATION TIMESTAMP: 06-05-2023 10:10:08)
---
> QUERY: (OPTIMIZATION TIMESTAMP: 06-05-2023 10:10:33)
72c72
< scan t2 223175 136847 293083 00:11.87 97
---
> scan t2 223175 136847 293083 00:12.33 97
76c76
< nljoin 223175 136610 00:11.90 502633
---
> nljoin 223175 136610 00:12.35 502633
80c80
< group 7 10 223175 00:12.01 300191
---
> group 7 10 223175 00:12.47 300191
94c94,95
< scan t1 889979 1 13740134 00:06.59 2
---
> scan t1 889979 1 13740134 00:06.90 2
>
I see further down the thread updating stats has helped. (Where is Spokey when you need him?)
Is PDQ set in the server's environment at start up? I see you posted at the top.
IFX_LOCK_MODE_WAIT=30
IFX_LARGE_PAGES=1
IFX_NETBUF_SIZE=65536
FET_BUF_SIZE=1024000
IFX_NETBUF_PVTPOOL_SIZE=2
PSORT_NPROCS=8
PSORT_DBTEMP=/opt/ramdisk/data
DBSPACETEMP=tmpdbs1:tmpdbs2:tmpdbs3:tmpdbs4:tmpdbs5:tmpdbs6
OPTOFC=1
IFX_USEPUT=1
PDQPRIORITY=100
Or is this just the environment for the client program?
Ben.
------------------------------
Benjamin Thompson
Original Message:
Sent: Mon June 05, 2023 03:30 PM
From: Art Kagel
Subject: PDQ - Why does its performance suck sooooo bad?
Curiouser and curiouser Jared!
Those two query plans are identical and I see no evidence of PDQ in either one. Both show "Maimum Threads: 0" which would indicate that they were both run under non-zero PDQPRIORITY ( = 1 ??).
I do see that the data distributions on the triangle and depvar tables are either stale or insufficiently detailed as the estimated and actual counts are very different.
Also the query has a correlated subquery which hurts performance (though I do understand that this is not related to the issue you reported). Here's a rewrite that should run faster regardless, and especially if you update statistics on those tables:
SELECT term_ann, gap_flag, prem_can_meth, count(*)
FROM triangle
INNER JOIN aimmastr
ON triangle.tba_no = aimmastr.tba_no AND area != 'ADD1'
LEFT JOIN depvar
ON triangle.tba_no = depvar.curr_tba_no
AND triangle.term_ann = depvar.curr_term_ann
AND triangle.prem_can_meth = depvar.curr_can_meth
AND noexclude_ctrlbrk = 'Y'
WHERE cancel_month = 5
AND pol_acctg_period <= 1475
AND eom_date <= "03/31/2023"
AND prem_amt > 0
AND depvar.curr_tba_no IS NULL
GROUP BY 1,2,3;
Test it though, sometimes putting filters ( noexclude_ctrlbrk = 'Y' ) in the ON clause of an outer join causes unexpected results. An index on depvar.curr_tba_no (with multi-index scan), or adding that column to the existing index on curr_term_ann and curr_can_meth, would speed things up even more.
Art
------------------------------
Art S. Kagel, President and Principal Consultant
ASK Database Management Corp.
www.askdbmgt.com
Original Message:
Sent: Mon June 05, 2023 11:12 AM
From: Jared Heath
Subject: PDQ - Why does its performance suck sooooo bad?
Here is are different queries from different programs.
This first program typically runs in about 1.5 minutes. With PDQ on, it goes to 10. It does a lot of different queries, but this one sticks out in the onstat....its doing the same nljoin stuff:
session effective #RSAM total used dynamic
id user user tty pid hostname threads memory memory explain
125 sncuser - - 2076 uatappx21.statenational.com 8 438272 435352 off
Program :
/snc/hos/bin/pasedit.4ge
tid name rstcb flags curstk status
193 sqlexec 82c59f60 Y--P--- 5072 running-
196 scan_1.0 82c5ba48 ------- 768 sleeping secs: 1 -
467035 group_29 82c5b150 ------- 608 running-
467036 nljoin_2 82c5de28 ------- 608 ready-
467037 nljoin_2 82c5c340 S------ 688 mutex wait sync_lock2-
467038 nljoin_2 82c5cc38 S------ 688 mutex wait sync_lock2-
467039 nljoin_2 82c58d70 S------ 688 mutex wait sync_lock2-
467040 scan_291 82c56990 Y------ 608 cond wait await_MC29-
Memory pools count 2
name class addr totalsize freesize #allocfrag #freefrag
125 V 98a16040 434176 2488 542 6
125*O0 V 989e8040 4096 744 1 1
name free used name free used
overhead 0 6704 scb 0 144
opentable 0 22848 filetable 0 3616
misc 0 320 log 0 132288
temprec 0 31840 keys 0 592
ralloc 0 81984 gentcb 0 6128
ostcb 0 2992 sqscb 0 29200
sql 0 8592 xchg_desc 0 10520
xchg_port 0 5656 xchg_packet 0 4368
xchg_group 0 456 xchg_priv 0 960
hashfiletab 0 4416 osenv 0 3008
sqtcb 0 62320 fragman 0 9432
shmblklist 0 2688 sapi 0 1832
rsam_seqscan 0 2136
sqscb info
scb sqscb optofc pdqpriority optcompind directives
836351c0 98a5b028 0 40 2 1
Sess SQL Current Iso Lock SQL ISAM F.E.
Id Stmt type Database Lvl Mode ERR ERR Vers Explain
125 SELECT tba CR Not Wait 0 0 9.41 Off
Current Role : sncfull
Current SQL statement (189022) :
select count ( * ) from stastcd , aimmisc where tba_no = ? and ins_co_no =
? and state = ? and corp_state = ?
Host variables :
address type flags value
-----------------------------------------
0x000000009bdac9b8 CHAR 0x000 40P
0x000000009bdaca48 CHAR 0x000 S8
0x000000009bdacad8 CHAR 0x000 CA
0x000000009bdacb68 CHAR 0x000 CA
Last parsed SQL statement :
select count ( * ) from stastcd , aimmisc where tba_no = ? and ins_co_no =
? and state = ? and corp_state = ?
143952 byte(s) of memory is allocated from the sscpool
The second program bounces back and forth between three queries. This one gets runtime above 3 seconds sometimes....in fact the one I ran for the attached explain runs several seconds for both. Non-PDQ first.
session effective #RSAM total used dynamic
id user user tty pid hostname threads memory memory explain
765 xx- - 1152 xxx 4 335872 321296 off
Program :
/snc/hos/bin/bbb.4ge
tid name rstcb flags curstk status
1401871 sqlexec 82c6b568 ---PX-- 8160 running-
1401876 scan_1.0 82c6c758 Y------ 608 cond wait await_MC1 -
1401877 scan_2.0 82c57b80 Y------ 608 cond wait await_MC2 -
1401878 scan_3.0 82c68890 Y------ 608 cond wait await_MC3 -
Memory pools count 2
name class addr totalsize freesize #allocfrag #freefrag
765 V b1da4040 327680 12872 451 16
765*O0 V b051a040 4096 744 1 1
name free used name free used
overhead 0 6704 scb 0 144
opentable 0 20568 filetable 0 3584
ru 0 1200 misc 0 320
log 0 66144 temprec 0 26240
keys 0 848 ralloc 0 65104
gentcb 0 3536 ostcb 0 2992
sort 0 104 sqscb 0 30032
sql 0 21112 xchg_desc 0 4544
xchg_port 0 3360 xchg_packet 0 1344
xchg_group 0 312 xchg_priv 0 512
hashfiletab 0 2208 osenv 0 3136
sqtcb 0 36096 fragman 0 12128
shmblklist 0 1912 sapi 0 1080
rsam_seqscan 0 3024
sqscb info
scb sqscb optofc pdqpriority optcompind directives
8356d200 b3070028 0 10 2 1
Sess SQL Current Iso Lock SQL ISAM F.E.
Id Stmt type Database Lvl Mode ERR ERR Vers Explain
765 SELECT tba CR Not Wait 0 0 9.41 Off
Current statement name : i0006ec6bzydk2kobw
Current Role : sncfull
Current SQL statement (1599) :
SELECT term_ann, gap_flag, prem_can_meth, count(*) FROM triangle,
aimmastr WHERE cancel_month = ? AND pol_acctg_period <= ? AND eom_date
<= ? AND triangle.tba_no = aimmastr.tba_no AND area != 'ADD1' AND
prem_amt > 0 AND triangle.tba_no NOT IN (SELECT curr_tba_no FROM
depvar WHERE exclude_ctrlbrk = 'Y' and triangle.term_ann =
depvar.curr_term_ann and triangle.prem_can_meth =
depvar.curr_can_meth) GROUP BY 1,2,3
QUERY_TIMEOUT setting: 0 (No Timeout)
Clock time elapsed : 00:00:02
Host variables :
address type flags value
-----------------------------------------
0x00000000ad0e9230 SMINT 0x000 29
0x00000000ad0e92c0 SMINT 0x000 1450
0x00000000ad0e9350 DATE 0x000 02/28/2023
Last parsed SQL statement :
select months_needed from trimthctrl where ? between beg_cycle_month and
end_cycle_month and ? between trimthctrl . eff_dt and trimthctrl . exp_dt
User-created Temp tables :
partnum tabname rowsize
1700002 t_cbrkfactor 22
100936 byte(s) of memory is allocated from the sscpool
QUERY: (OPTIMIZATION TIMESTAMP: 06-05-2023 10:10:08)
------
SELECT term_ann, gap_flag, prem_can_meth, count(*)
FROM triangle, aimmastr
WHERE cancel_month = 5
AND pol_acctg_period <= 1475
AND eom_date <= "03/31/2023"
AND triangle.tba_no = aimmastr.tba_no
AND area != 'ADD1'
AND prem_amt > 0
AND triangle.tba_no NOT IN
(SELECT curr_tba_no
FROM depvar
WHERE exclude_ctrlbrk = 'Y'
and triangle.term_ann = depvar.curr_term_ann
and triangle.prem_can_meth = depvar.curr_can_meth)
GROUP BY 1,2,3
Estimated Cost: 802823
Estimated # of Rows Returned: 9
Maximum Threads: 0
Temporary Files Required For: Group By
1) informix.aimmastr: SEQUENTIAL SCAN
Filters: informix.aimmastr.area != 'ADD1'
2) informix.triangle: INDEX PATH
Filters: ((informix.triangle.prem_amt > $0.00 AND informix.triangle.tba_no != ALL <subquery> ) AND informix.triangle.eom_date <= 03/31/2023 )
(1) Index Name: informix.i_triangle3
Index Keys: tba_no cancel_month pol_acctg_period (Parallel, fragments: ALL)
Lower Index Filter: (informix.triangle.tba_no = informix.aimmastr.tba_no AND informix.triangle.cancel_month = 5 )
Upper Index Filter: informix.triangle.pol_acctg_period <= 1475
NESTED LOOP JOIN
Subquery:
---------
Estimated Cost: 2
Estimated # of Rows Returned: 1
Maximum Threads: 1
1) informix.depvar: INDEX PATH
Filters: informix.depvar.exclude_ctrlbrk = 'Y'
(1) Index Name: informix.i_depvar2
Index Keys: curr_term_ann curr_can_meth (Parallel, fragments: ALL)
Lower Index Filter: (informix.depvar.curr_term_ann = informix.triangle.term_ann AND informix.depvar.curr_can_meth = informix.triangle.prem_can_meth )
Query statistics:
-----------------
Table map :
----------------------------
Internal name Table name
----------------------------
t1 aimmastr
t2 triangle
type table rows_prod est_rows rows_scan time est_cost
-------------------------------------------------------------------
scan t1 5171 5171 5180 00:00.00 732
type table rows_prod est_rows rows_scan time est_cost
-------------------------------------------------------------------
scan t2 223175 136847 293083 00:11.87 97
type rows_prod est_rows time est_cost
-------------------------------------------------
nljoin 223175 136610 00:11.90 502633
type rows_prod est_rows rows_cons time est_cost
------------------------------------------------------------
group 7 10 223175 00:12.01 300191
Subquery statistics:
--------------------
Table map :
----------------------------
Internal name Table name
----------------------------
t1 depvar
type table rows_prod est_rows rows_scan time est_cost
-------------------------------------------------------------------
scan t1 889979 1 13740134 00:06.59 2
QUERY: (OPTIMIZATION TIMESTAMP: 06-05-2023 10:10:33)
------
SELECT term_ann, gap_flag, prem_can_meth, count(*)
FROM triangle, aimmastr
WHERE cancel_month = 5
AND pol_acctg_period <= 1475
AND eom_date <= "03/31/2023"
AND triangle.tba_no = aimmastr.tba_no
AND area != 'ADD1'
AND prem_amt > 0
AND triangle.tba_no NOT IN
(SELECT curr_tba_no
FROM depvar
WHERE exclude_ctrlbrk = 'Y'
and triangle.term_ann = depvar.curr_term_ann
and triangle.prem_can_meth = depvar.curr_can_meth)
GROUP BY 1,2,3
Estimated Cost: 802823
Estimated # of Rows Returned: 9
Maximum Threads: 0
Temporary Files Required For: Group By
1) informix.aimmastr: SEQUENTIAL SCAN
Filters: informix.aimmastr.area != 'ADD1'
2) informix.triangle: INDEX PATH
Filters: ((informix.triangle.prem_amt > $0.00 AND informix.triangle.tba_no != ALL <subquery> ) AND informix.triangle.eom_date <= 03/31/2023 )
(1) Index Name: informix.i_triangle3
Index Keys: tba_no cancel_month pol_acctg_period (Parallel, fragments: ALL)
Lower Index Filter: (informix.triangle.tba_no = informix.aimmastr.tba_no AND informix.triangle.cancel_month = 5 )
Upper Index Filter: informix.triangle.pol_acctg_period <= 1475
NESTED LOOP JOIN
Subquery:
---------
Estimated Cost: 2
Estimated # of Rows Returned: 1
Maximum Threads: 1
1) informix.depvar: INDEX PATH
Filters: informix.depvar.exclude_ctrlbrk = 'Y'
(1) Index Name: informix.i_depvar2
Index Keys: curr_term_ann curr_can_meth (Parallel, fragments: ALL)
Lower Index Filter: (informix.depvar.curr_term_ann = informix.triangle.term_ann AND informix.depvar.curr_can_meth = informix.triangle.prem_can_meth )
Query statistics:
-----------------
Table map :
----------------------------
Internal name Table name
----------------------------
t1 aimmastr
t2 triangle
type table rows_prod est_rows rows_scan time est_cost
-------------------------------------------------------------------
scan t1 5171 5171 5180 00:00.00 732
type table rows_prod est_rows rows_scan time est_cost
-------------------------------------------------------------------
scan t2 223175 136847 293083 00:12.33 97
type rows_prod est_rows time est_cost
-------------------------------------------------
nljoin 223175 136610 00:12.35 502633
type rows_prod est_rows rows_cons time est_cost
------------------------------------------------------------
group 7 10 223175 00:12.47 300191
Subquery statistics:
--------------------
Table map :
----------------------------
Internal name Table name
----------------------------
t1 depvar
type table rows_prod est_rows rows_scan time est_cost
-------------------------------------------------------------------
scan t1 889979 1 13740134 00:06.90 2