At UKOUG Tech’15 (Super Sunday) there was a session called "12c: A Closer Look at the Multi-Process Multi-Threaded Model for Oracle on Linux/Unix" by Markus Flechtner. Since then I can’t stop thinking about the performance of this feature. Why Oracle decided to provide it?
I did some tests regarding sort operations and threaded execution was always a bit slower. I decided to dig a little dipper into this.
Oracle instance with threaded_execution=false:
SQL> sho parameters threaded_execution
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
threaded_execution boolean FALSE
SQL> select count(1) from sales2;
COUNT(1)
----------
58805952
SQL> select count(distinct file# || block#)
2 from v$bh b, dba_objects o
3 where b.objd=o.data_object_id
4 and o.object_name='SALES2'
5 and b.status!='free';
COUNT(DISTINCTFILE#||BLOCK#)
----------------------------
283624
SQL> select blocks from user_segments where segment_name='SALES2';
BLOCKS
----------
284672
Oracle instance with threaded_execution=true:
SQL> sho parameters threaded_execution
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
threaded_execution boolean TRUE
SQL> select count(1) from sales2;
COUNT(1)
----------
58805952
SQL> select count(distinct file# || block#)
2 from v$bh b, dba_objects o
3 where b.objd=o.data_object_id
4 and o.object_name='SALES2'
5 and b.status!='free';
COUNT(DISTINCTFILE#||BLOCK#)
----------------------------
283624
SQL> select blocks from user_segments where segment_name='SALES2';
BLOCKS
----------
284672
As you can see, I have the same table (SALES2) on both instances, which is cached in buffer cache.
Now let’s test some kind of query, that access only this one table:
Oracle instance with threaded_execution=false:
SQL> set timing on SQL> get bigsort 1 with v_sales as 2 ( 3 select s.*, row_number() over (order by amount_sold desc) as rn 4 from sales2 s 5 ) 6 select * 7 from v_sales 8* where rn<=2 SQL> / PROD_ID CUST_ID TIME_ID CHANNEL_ID PROMO_ID QUANTITY_SOLD AMOUNT_SOLD ---------- ---------- --------- ---------- ---------- ------------- ----------- RN ---------- 18 510 03-JAN-99 3 999 1 1782.72 1 18 1330 03-JAN-99 3 999 1 1782.72 2 Elapsed: 00:00:11.98
Oracle instance with threaded_execution=true:
SQL> set timing on SQL> get bigsort 1 with v_sales as 2 ( 3 select s.*, row_number() over (order by amount_sold desc) as rn 4 from sales2 s 5 ) 6 select * 7 from v_sales 8* where rn<=2 SQL> / PROD_ID CUST_ID TIME_ID CHANNEL_ID PROMO_ID QUANTITY_SOLD AMOUNT_SOLD ---------- ---------- --------- ---------- ---------- ------------- ----------- RN ---------- 18 510 03-JAN-99 3 999 1 1782.72 1 18 1330 03-JAN-99 3 999 1 1782.72 2 Elapsed: 00:00:12.58
I used perf to analyze those two executions and I found a lot more syscalls, when threaded execution was used. I noticed also that in threaded execution, oracle is using nsmore2recv function. When I googled it, I found a great article by Tanel Poder: https://blog.tanelpoder.com/2008/02/05/oracle-hidden-costs-revealed-part-1/
Using strace revealed similar situation to this described by Tanel – a lot of POLL syscalls.
Oracle instance with threaded_execution=false:
[root@rico ~]# strace -cp 12168 Process 12168 attached ^CProcess 12168 detached % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 0.00 0.000000 0 2 read 0.00 0.000000 0 2 write 0.00 0.000000 0 1 semctl 0.00 0.000000 0 159 getrusage 0.00 0.000000 0 12 times 0.00 0.000000 0 3 semtimedop ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000000 179 total
Oracle instance with threaded_execution=true:
[root@rico fd]# strace -cp 12165
Process 12165 attached
^CProcess 12165 detached
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
84.22 0.113706 0 980840 poll
10.37 0.014000 7000 2 read
5.41 0.007310 1218 6 semtimedop
0.00 0.000000 0 2 write
0.00 0.000000 0 1 semctl
0.00 0.000000 0 419 getrusage
0.00 0.000000 0 12 times
------ ----------- ----------- --------- --------- ----------------
100.00 0.135016 981282 total
[root@rico fd]# strace -p 12165 -o /tmp/threaded_exec.out
Process 12165 attached
^CProcess 12165 detached
[root@rico fd]# grep poll /tmp/threaded_exec.out | tail
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
poll([{fd=63, events=POLLIN|POLLRDNORM}], 1, 0) = 0 (Timeout)
The STID 12165 was signed to SPID 8107:
SQL> get spid
1 select spid, stid
2 from v$process p, v$session s
3 where p.addr=s.paddr
4* and s.sid=sys_context('userenv','sid')
SQL> /
SPID STID
------------------------ ------------------------
8107 12165
Let’s check the file descriptors for this thread:
[root@rico ~]# cd /proc/8107/task/12165/fd [root@rico fd]# ls -al | grep 63 lrwx------. 1 oracle oinstall 64 12-17 21:38 63 -> socket:[73968] [root@rico fd]# lsof | grep 73968 ora_scmn_ 8107 oracle 63u IPv6 73968 0t0 TCP localhost:ncube-lm->localhost:32400 (ESTABLISHED) [root@rico fd]# ps aux | grep 8107 | grep -v grep oracle 8107 4.7 29.0 6155520 2901516 ? Ssl 20:01 6:54 ora_u005_orclth [root@rico fd]#
So it looks like, that the process ora_u00N is using sockets to communicate with its threads. That’s why we have seen the additional syscalls, which were an overhead causing slower execution.
So I raise the question: why and when use threaded execution? If ever?