Once again about physical reads prefetch

It seems there is one mechanics for physical reads prefetch thoroughly described by Tanel Poder in his very useful blog:
http://blog.tanelpoder.com/2012/05/02/advanced-oracle-troubleshooting-guide-part-10-index-unique-scan-doing-multiblock-reads/

Let’s create a new table and populate it with an append operation:
like:

DROP TABLE IDXTEST;

CREATE TABLE IDXTEST
AS select (1e&pw) id, 1e4 id2, rpad(‘a’,999,’a’) filler
from dual where rownum <100;

———————————————————————–
disconnect
connect REMIDM/….@ORASOL11

insert /*+ APPEND */ into IDXTEST select 1e&pw + trunc(rownum/20)+1 id, mod(rownum,20) id2, rpad('a',999,'b') filler
from dual connect by level <=292*120+1 order by dbms_random.value;
commit;

CREATE INDEX IDXTEST_IX1 ON IDXTEST(id) PCTFREE 96;

let’s reconnect the session again (that’s an important part I’ll describe later),
parse the statement before to not spoil statistic by parsing the statement
and finally execute it:

disconnect
connect REMIDM/….@ORASOL11

DEFINE SQLSTMT =” /*+ dynamic_sampling(t 0) INDEX(t)*/ * from IDXTEST t WHERE id between :id1 and :id2 AND id2 IN (:l1,:l2,:l3,:l4,:l5,:l6,:l7,:l8)”

DECLARE
c number;
v_sql CLOB;
BEGIN
c := dbms_sql.open_cursor;
v_sql := ‘SELECT &SQLSTMT ‘;

DBMS_SQL.parse(c,v_sql,DBMS_SQL.NATIVE);
DBMS_SQL.close_cursor(c);
END;

alter session set events ‘sql_trace {pgadep: exactdepth 0} plan_stat=all_executions,wait=true,bind=false’;
—-
SELECT &SQLSTMT
/

alter session set events ‘sql_trace off’;

You would see quite common picture of the mix of db file scattered read/db file sequential read wait events:

WAIT #18446604434622825216: nam='db file scattered read' ela= 27 file#=4 block#=278163 blocks=5 obj#=78095 tim=5870483662
WAIT #18446604434622825216: nam='db file scattered read' ela= 23 file#=4 block#=277469 blocks=3 obj#=78095 tim=5870483776
................................
WAIT #18446604434622825216: nam='db file scattered read' ela= 30 file#=4 block#=277776 blocks=4 obj#=78095 tim=5870490796
WAIT #18446604434622825216: nam='db file scattered read' ela= 21 file#=4 block#=277366 blocks=2 obj#=78095 tim=5870490913
WAIT #18446604434622825216: nam='SQL*Net more data to client' ela= 355 driver id=1413697536 #bytes=8144 p3=0 obj#=78095 tim=5870491493
WAIT #18446604434622825216: nam='db file sequential read' ela= 28 file#=4 block#=277543 blocks=1 obj#=78095 tim=5870491962
FETCH #18446604434622825216:c=110000,e=112518,p=4966,cr=6785,cu=0,mis=0,r=1811,dep=0,og=1,plh=3072623726,tim=5870493352
STAT #18446604434622825216 id=1 cnt=1812 pid=0 pos=1 obj=0 op='FILTER  (cr=6790 pr=4974 pw=0 time=113400 us)'
STAT #18446604434622825216 id=2 cnt=1812 pid=1 pos=1 obj=78095 op='TABLE ACCESS BY INDEX ROWID IDXTEST (cr=6790 pr=4974 pw=0 time=103426 us cost=15855 size=527 card=1)'
STAT #18446604434622825216 id=3 cnt=6039 pid=2 pos=1 obj=78097 op='INDEX RANGE SCAN IDXTEST_IX1 (cr=758 pr=0 pw=0 time=37630 us cost=1767 size=0 card=33)'

It looks quite common so far: db file sequential read and db file scattered read
wait events in the trace file.

BUT let’s now comment out that reconnect part I mentioned before, like:
—disconnect
—connect REMIDM/…@ORASOL11
and almost the same code snippet would give a very different result:

WAIT #18446604434620761192: nam='SQL*Net more data to client' ela= 237 driver id=1413697536 #bytes=8145 p3=0 obj#=78100 tim=7011492476
WAIT #18446604434620761192: nam='db file parallel read' ela= 489 files=1 blocks=10 requests=10 obj#=78100 tim=7011493165
WAIT #18446604434620761192: nam='db file parallel read' ela= 1026 files=1 blocks=14 requests=14 obj#=78100 tim=7011494469
WAIT #18446604434620761192: nam='db file parallel read' ela= 510 files=1 blocks=12 requests=12 obj#=78100 tim=7011495247
WAIT #18446604434620761192: nam='db file parallel read' ela= 454 files=1 blocks=12 requests=12 obj#=78100 tim=7011495987
WAIT #18446604434620761192: nam='db file scattered read' ela= 31 file#=4 block#=270730 blocks=3 obj#=78100 tim=7011496204
WAIT #18446604434620761192: nam='db file parallel read' ela= 469 files=1 blocks=12 requests=12 obj#=78100 tim=7011496786
WAIT #18446604434620761192: nam='db file parallel read' ela= 478 files=1 blocks=11 requests=11 obj#=78100 tim=7011497492
WAIT #18446604434620761192: nam='db file scattered read' ela= 27 file#=4 block#=270323 blocks=3 obj#=78100 tim=7011497695
WAIT #18446604434620761192: nam='db file parallel read' ela= 247 files=1 blocks=5 requests=5 obj#=78100 tim=7011498056
WAIT #18446604434620761192: nam='db file parallel read' ela= 622 files=1 blocks=15 requests=15 obj#=78100 tim=7011498872
WAIT #18446604434620761192: nam='db file parallel read' ela= 525 files=1 blocks=14 requests=14 obj#=78100 tim=7011499608
WAIT #18446604434620761192: nam='db file parallel read' ela= 454 files=1 blocks=10 requests=10 obj#=78100 tim=7011500268
WAIT #18446604434620761192: nam='db file parallel read' ela= 466 files=1 blocks=11 requests=11 obj#=78100 tim=7011500960
WAIT #18446604434620761192: nam='db file parallel read' ela= 337 files=1 blocks=8 requests=8 obj#=78100 tim=7011501561
WAIT #18446604434620761192: nam='db file scattered read' ela= 34 file#=4 block#=271372 blocks=3 obj#=78100 tim=7011501748
FETCH #18446604434620761192:c=380000,e=191593,p=3769,cr=6777,cu=0,mis=0,r=1811,dep=0,og=1,plh=3072623726,tim=7011501866
STAT #18446604434620761192 id=1 cnt=1812 pid=0 pos=1 obj=0 op='FILTER  (cr=6786 pr=3817 pw=0 time=85684 us)'
STAT #18446604434620761192 id=2 cnt=1812 pid=1 pos=1 obj=78100 op='TABLE ACCESS BY INDEX ROWID IDXTEST (cr=6786 pr=3817 pw=0 time=79849 us cost=3976 size=527 card=1)'
STAT #18446604434620761192 id=3 cnt=6039 pid=2 pos=1 obj=78101 op='INDEX RANGE SCAN IDXTEST_IX1 (cr=759 pr=0 pw=0 time=11601 us cost=445 size=0 card=33)'

You see a plenty of “db file parallel read” waits, which seems a clear indication of “prefetch” mechanics in action.

One more indirect argument in supporting this thesis is behaviour after:

ALTER SYSTEM SET “_table_lookup_prefetch_size” =80 scope =spfile;

When “_table_lookup_prefetch_size” = 40 I see last wait events in the trace like:

WAIT #18446604434576175608: nam='db file parallel read' ela= 2068 files=1 blocks=39 requests=39 obj#=78158 tim=26289076453
WAIT #18446604434576175608: nam='db file scattered read' ela= 53 file#=4 block#=269568 blocks=8 obj#=78158 tim=26289076664
WAIT #18446604434576175608: nam='db file parallel read' ela= 1340 files=1 blocks=39 requests=39 obj#=78158 tim=26289078178
WAIT #18446604434576175608: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=78158 tim=26289078322
WAIT #18446604434576175608: nam='db file scattered read' ela= 78 file#=4 block#=269936 blocks=8 obj#=78158 tim=26289078584
WAIT #18446604434576175608: nam='db file parallel read' ela= 1566 files=1 blocks=38 requests=38 obj#=78158 tim=26289080288
WAIT #18446604434576175608: nam='db file scattered read' ela= 39 file#=4 block#=269289 blocks=7 obj#=78158 tim=26289080555
WAIT #18446604434576175608: nam='db file parallel read' ela= 1981 files=1 blocks=39 requests=39 obj#=78158 tim=26289082686

If “_table_lookup_prefetch_size” = 80:

WAIT #18446604434621780232: nam='db file parallel read' ela= 6790 files=1 blocks=79 requests=79 obj#=78168 tim=28714230362
WAIT #18446604434621780232: nam='db file sequential read' ela= 17 file#=4 block#=275977 blocks=1 obj#=78168 tim=28714230584
WAIT #18446604434621780232: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=78168 tim=28714230633
WAIT #18446604434621780232: nam='db file parallel read' ela= 2209 files=1 blocks=75 requests=75 obj#=78168 tim=28714233103
WAIT #18446604434621780232: nam='db file scattered read' ela= 71 file#=4 block#=276504 blocks=5 obj#=78168 tim=28714233474
WAIT #18446604434621780232: nam='db file parallel read' ela= 1774 files=1 blocks=77 requests=77 obj#=78168 tim=28714235434
WAIT #18446604434621780232: nam='db file sequential read' ela= 19 file#=4 block#=275970 blocks=1 obj#=78168 tim=28714235722
WAIT #18446604434621780232: nam='db file parallel read' ela= 19067 files=1 blocks=73 requests=73 obj#=78168 tim=28714255008
WAIT #18446604434621780232: nam='db file parallel read' ela= 2064 files=1 blocks=74 requests=74 obj#=78168 tim=28714257598

Small indirect result of previous post

It seems I’ve managed to decypher one more function from Alexander Anokhin’s blog, i.e. kcblnb_dscn

let’s have a look at dtracelio.d output

kcbgcur(0xFFFF80FFBFFF9640,2,247,0) [tsn: 3 rdba: 0x40c980 (1/51584) obj: -40016380 dobj: 4245888] where: 247 mode_held: 2
kcblnb_dscn(0xFFFF80FFBDDEAA00,18235954397446147,6,0)

if you have a look at second parameter of kcblnb_dscn(18235954397446147) in hex formatyou would see:
40C98100000003 and 40C981 is looking very familiar, is not it?
Very close to rdba: 40c980 and 3 is a number of my TEMP tablespace,

So I’ve append the script with the following parts:

pid$1::kcblnb_dscn:entry
{
rdba2 = arg1 >>32;
tsn2 = arg1 & 0xFFFFFFFF;
}

pid$1::kcblnb:entry, pid$1::kcblnb_dscn:entry
/trace_logical_io && show_lio_calls/
{
printf(“%s(0x%X,0x%X,%d,%d) [tsn: %d rdba: 0x%x )]\n”,probefunc,arg0,arg1,arg2,arg3, tsn2, rdba2);
}

and got result, like :

kcbgcur(0xFFFF80FFBFFF9D80,2,252,0) [tsn: 3 rdba: 0x40c400 (1/50176) obj: -40016374 dobj: 4244224] where: 252 mode_held: 2
kcbgtcr(0xFFFF80FFBFFF8B10,1,43,0) [tsn: 2 rdba: 0xc000e0 (3/224) obj: 0 dobj: -1] where: 43 exam: 1
kcbgcur(0xFFFF80FFBFFF9D80,2,252,0) [tsn: 3 rdba: 0x40c380 (1/50048) obj: -40016374 dobj: 4244224] where: 252 mode_held: 2
kcbgtcr(0xFFFF80FFBFFF8B10,1,43,0) [tsn: 2 rdba: 0xc000e0 (3/224) obj: 0 dobj: -1] where: 43 exam: 1
kcbgcur(0xFFFF80FFBFFF9690,2,247,0) [tsn: 3 rdba: 0x40c300 (1/49920) obj: -40016374 dobj: 4244224] where: 247 mode_held: 2
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30100000003,6,0) [tsn: 3  rdba: 40c301 )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30200000003,6,0) [tsn: 3  rdba: 40c302 )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30300000003,6,0) [tsn: 3  rdba: 40c303 )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30400000003,6,0) [tsn: 3  rdba: 40c304 )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30500000003,6,0) [tsn: 3  rdba: 40c305 )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30600000003,6,0) [tsn: 3  rdba: 40c306 )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30700000003,6,0) [tsn: 3  rdba: 40c307 )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30800000003,6,0) [tsn: 3  rdba: 40c308 )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30900000003,6,0) [tsn: 3  rdba: 40c309 )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30A00000003,6,0) [tsn: 3  rdba: 40c30a )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30B00000003,6,0) [tsn: 3  rdba: 40c30b )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30C00000003,6,0) [tsn: 3  rdba: 40c30c )]
kcblnb_dscn(0xFFFF80FFBDDEAA00,0x40C30D00000003,6,0) [tsn: 3  rdba: 40c30d )]

One more subquery factoring oddity/feature

Recently Jonathan Lewis published a mavelous blog series about subquery factoring: https://jonathanlewis.wordpress.com/2015/07/27/subquery-factoring-10/
I’ve managed to observed one more : parallel queries with subquery factoring tends to have PARALLEL TO SERIAL step in the execution plan.

I’ve created table as

CREATE TABLE PTEST TABLESPACE USERS
AS select rpad(‘z’,20,’z’) || (trunc(rownum/2)+1) id, rpad(‘a’,999,’a’) filler from dual connect by level <=1e4 order by dbms_random.value;

and the parallel query looks like:

 

ALTER SESSION FORCE PARALLEL QUERY PARALLEL 4;

with p as (SELECT * from PTEST where id>’a’)
SELECT * FROM p p0, p p1
WHERE p0.id=p1.id;

 

corresponding execution plan is :

Plan hash value: 2939472082 

-------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | TQ |IN-OUT| PQ Distrib |
--------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 230 (100)| | | | |
| 1 | TEMP TABLE TRANSFORMATION | | | | | | | | |
| 2 | PX COORDINATOR | | | | | | | | |
| 3 | PX SEND QC (RANDOM) | :TQ10000 | 10876 | 5661K| 110 (0)| 00:00:02 | Q1,00 | P->S | QC (RAND) |
| 4 | LOAD AS SELECT | | | | | | Q1,00 | PCWP | |
| 5 | PX BLOCK ITERATOR | | 10876 | 5661K| 110 (0)| 00:00:02 | Q1,00 | PCWC | |
|* 6 | TABLE ACCESS FULL | PTEST | 10876 | 5661K| 110 (0)| 00:00:02 | Q1,00 | PCWP | |
| 7 | PX COORDINATOR | | | | | | | | |
| 8 | PX SEND QC (RANDOM) | :TQ20002 | 31719 | 32M| 120 (1)| 00:00:02 | Q2,02 | P->S | QC (RAND) |
|* 9 | HASH JOIN BUFFERED | | 31719 | 32M| 120 (1)| 00:00:02 | Q2,02 | PCWP | |
| 10 | PX RECEIVE | | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,02 | PCWP | |
| 11 | PX SEND HASH | :TQ20000 | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,00 | P->P | HASH |
| 12 | VIEW | | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,00 | PCWP | |
| 13 | PX BLOCK ITERATOR | | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,00 | PCWC | |
|* 14| TABLE ACCESS FULL | SYS_TEMP_0FD9D6600_29614D6 | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,00 | PCWP | |
| 15 | PX RECEIVE | | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,02 | PCWP | |
| 16 | PX SEND HASH | :TQ20001 | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,01 | P->P | HASH |
| 17 | VIEW | | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,01 | PCWP | |
| 18 | PX BLOCK ITERATOR | | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,01 | PCWC | |
|* 19 | TABLE ACCESS FULL | SYS_TEMP_0FD9D6600_29614D6 | 10876 | 5661K| 60 (0)| 00:00:01 | Q2,01 | PCWP | |
--------------------------------------------------------------------------------------------

You can see P->S part in the middle of the execution plan:| 3 | PX SEND QC (RANDOM) | :TQ10000 |…. | P->S |

SQL Plan Monitoring Details (Plan Hash Value=2939472082)                                  
=======================================================================================   
| Id |          Operation          |            Name            | ....... |    Rows   |   
|    |                             |                            | ....... |  (Actual) |   
=======================================================================================   
|  0 | SELECT STATEMENT            |                            |         |     19998 |   
|  1 |   TEMP TABLE TRANSFORMATION |                            |         |     19998 |   
|  2 |    PX COORDINATOR           |                            |         |         4 |   
|  3 |     PX SEND QC (RANDOM)     | :TQ10000                   |   ..... |         4 |   
|  4 |      LOAD AS SELECT         |                            |         |         4 |   
|  5 |       PX BLOCK ITERATOR     |                            |   ..... |     10000 |   
|  6 |        TABLE ACCESS FULL    | PTEST                      |   ..... |     10000 |   
|  7 |    PX COORDINATOR           |                            |         |     19998 |   
|  8 |     PX SEND QC (RANDOM)     | :TQ20002                   |   ......|     19998 |   
|  9 |      HASH JOIN BUFFERED     |                            |   ..... |     19998 |   
| 10 |       PX RECEIVE            |                            |   ..... |     10000 |   
| 11 |        PX SEND HASH         | :TQ20000                   |   ..... |     10000 |   
| 12 |         VIEW                |                            |   ..... |     10000 |   
| 13 |          PX BLOCK ITERATOR  |                            |   ..... |     10000 |   
| 14 |           TABLE ACCESS FULL | SYS_TEMP_0FD9D6600_29614D6 |   ..... |     10000 |   
| 15 |       PX RECEIVE            |                            |   ..... |     10000 |   
| 16 |        PX SEND HASH         | :TQ20001                   |   ..... |     10000 |   
| 17 |         VIEW                |                            |   ..... |     10000 |   
| 18 |          PX BLOCK ITERATOR  |                            |   ..... |     10000 |   
| 19 |           TABLE ACCESS FULL | SYS_TEMP_0FD9D6600_29614D6 |   ..... |     10000 |   
=======================================================================================   
                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                   

Only 4 rows seems were treated by the query coordinator (QC).
Let’s have a look what exact rows were read by QC. I’ll use again dtraclio.d developed by Alexander Anokhin.

After monitoring QC process I got (where obj: -40016384 dobj: 4246144 – represents temporary object in SYS schema):

================================= Logical I/O Summary (grouped by object) ============= 
 object_id  data_object_id       lio        cr    cr (e)    cr (d)        cu    cu (d)  
---------- --------------- --------- --------- --------- --------- --------- ---------  
        60              60         1         1         0         0         0         0  
 -40016384              -2         1         1         0         0         0         0  
         7               7         1         1         1         0         0         0  
        46              46         1         1         1         0         0         0  
        36              36         2         2         1         0         0         0  
        37              37         6         6         4         0         0         0  
       426             426        10        10         5         0         0         0  
        78              78        15        15         0         0         0         0  
         0              -1        29         7         7         0        22         0  
     77939           77939       151       151         0         0         0         0  
 -40016384         4246144       233        12         0         0       221       127  
---------- --------------- --------- --------- --------- --------- --------- ---------  
     total                       450       207        19         0       243       127  
======================================================================================= 
                                                                                        
Legend                                                                                  
lio      : logical gets (cr + cu)                                                       
cr       : consistent gets                                                              
cr (e)   : consistent gets - examination                                                
cr (d)   : consistent gets direct                                                       
cu       : db block gets                                                                
cu (d)   : db block gets direct                                                         
ispnd (Y): buffer is pinned count                                                       
ispnd (N): buffer is not pinned count                                                   
pin rls  : pin releases                                                                 

It seems pretty much LIO has been done by QC, however let’s have a look on details.
You will see that QC is reading 4 blocks again and again (mostly in “current” mode):

kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40c980 (1/51584) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcbnew(0xFFFF80FFBFFF8260,1,273,4294967295) [tsn: 3 rdba: 0x40ca80 (1/51840) obj: -40016384 dobj: 4246144] where: 273 mode_held:  blocks: 1
kcbnew(0xFFFF80FFBFFF8260,1,273,4294967295) [tsn: 3 rdba: 0x40ca00 (1/51712) obj: -40016384 dobj: 4246144] where: 273 mode_held:  blocks: 1
kcbnew(0xFFFF80FFBFFF8260,1,273,4294967295) [tsn: 3 rdba: 0x40c980 (1/51584) obj: -40016384 dobj: 4246144] where: 273 mode_held:  blocks: 1
kcbnew(0xFFFF80FFBFFF8260,1,273,4294967295) [tsn: 3 rdba: 0x40c900 (1/51456) obj: -40016384 dobj: 4246144] where: 273 mode_held:  blocks: 1
kcbnew(0xFFFF80FFBFFF8260,1,273,4294967295) [tsn: 3 rdba: 0x40c880 (1/51328) obj: -40016384 dobj: 4246144] where: 273 mode_held:  blocks: 1
kcbgcur(0xFFFF80FFBFFF88B0,2,65618,0) [tsn: 2 rdba: 0xc000d0 (3/208) obj: 0 dobj: -1] where: 82 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,128,0) [tsn: 2 rdba: 0xc000d0 (3/208) obj: 0 dobj: -1] where: 128 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40c880 (1/51328) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40c900 (1/51456) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40ca00 (1/51712) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40c980 (1/51584) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40c880 (1/51328) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40c980 (1/51584) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40c900 (1/51456) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40c900 (1/51456) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9A60,2,33,0) [tsn: 3 rdba: 0x40ca00 (1/51712) obj: -40016384 dobj: 4246144] where: 33 mode_held: 2
kcblnb_dscn(0xFFFF80FFBDDEAA00,18237071088943107,6,0)
kcblnb_dscn(0xFFFF80FFBDDEAA00,18237075383910403,6,0)
.......................................................................................
kcbgcur(0xFFFF80FFBFFF9640,2,247,0) [tsn: 3 rdba: 0x40ca00 (1/51712) obj: -40016384 dobj: 4246144] where: 247 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9740,2,248,0) [tsn: 3 rdba: 0x40c980 (1/51584) obj: -40016384 dobj: 4246144] where: 248 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9640,2,338,0) [tsn: 3 rdba: 0x40ca00 (1/51712) obj: -40016384 dobj: 4246144] where: 338 mode_held: 2
kcbgcur(0xFFFF80FFBFFF92C0,2,257,0) [tsn: 3 rdba: 0x40c980 (1/51584) obj: -40016384 dobj: 4246144] where: 257 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9640,2,249,0) [tsn: 3 rdba: 0x40ca00 (1/51712) obj: -40016384 dobj: 4246144] where: 249 mode_held: 2
kcbgcur(0xFFFF80FFBFFF89E0,2,65615,0) [tsn: 2 rdba: 0xc000d0 (3/208) obj: 0 dobj: -1] where: 79 mode_held: 2
kcbgcur(0xFFFF80FFBFFF9C10,2,250,0) [tsn: 3 rdba: 0x40c47f (1/50303) obj: -40016384 dobj: 4246144] where: 250 mode_held: 2
kcbgcur(0xFFFF80FFBFFF8D00,2,771,0) [tsn: 3 rdba: 0x40ca00 (1/51712) obj: -40016384 dobj: 4246144] where: 771 mode_held: 2
kcbgcur(0xFFFF80FFBFFF8E00,2,772,0) [tsn: 3 rdba: 0x40c980 (1/51584) obj: -40016384 dobj: 4246144] where: 772 mode_held: 2

and the final part of the puzzle, let’s query buffer cache header for the block which where read by QS, like:

select class,
decode(bh.state,0,’free’,1,’xcur’,2,’scur’,3,’cr’,4,’read’,5,’mrec’,
6,’irec’,7,’write’,8,’pi’, 9,’memory’,10,’mwrite’,
11,’donated’, 12,’protected’,13,’securefile’, 14,’siop’,15,’recckpt’
) state,
decode(bh.class,1,’data block’,2,’sort block’,3,’save undo block’,
4,’segment header’,5,’save undo header’,6,’free list’,7,’extent map’,
8,’1st level bmb’,9,’2nd level bmb’,10,’3rd level bmb’, 11,’bitmap block’,
12,’bitmap index block’,13,’file header block’,14,’unused’,
15,’system undo header’,16,’system undo block’, 17,’undo header’,
18,’undo block’
) block_class,
decode(bitand(bh.flag,1),0, ‘N’, ‘Y’) dirty,
decode(bitand(bh.flag,16), 0, ‘N’, ‘Y’) temp,
decode(bitand(bh.flag,1536), 0, ‘N’, ‘Y’) ping,
decode(bitand(bh.flag,16384), 0, ‘N’, ‘Y’) stale,
decode(bitand(bh.flag,65536), 0, ‘N’, ‘Y’) direct,
obj from x$bh bh where
1=1 AND obj=4246144

4	free	segment header	N	N	N	N	N	4246144
4	free	segment header	N	N	N	N	N	4246144
4	free	segment header	N	N	N	N	N	4246144
4	free	segment header	N	N	N	N	N	4246144

So it seems not a big issue with that parallel to serial step in the execution plan,
but QS is constantly reading and giving back to consumers the temporary segment header.
Actually it’s segment headers, number of headers is equal to your degree of parallelism.