Sunday, November 5, 2017

LOAD_BALANCE OFF Still checks other ADDRESS list. DB Connection consideration.


This note highlight performance penalty that can comes with using database connection with multiple address, contradicting what oracle document says, at least at "surface level".
this is worth considering when setting up application connection in DR/dataguard consideration

even when the first address is available i.e. DB is active, you notice stark difference in terms of percentage of time for connection. in this test, there was more than 6 times difference
between using one ADDRESS and two ADDRESS

1. Two TNS entry are created to test. TNS Client version 11.2.0.1.0
first TNS entry use one ADDRESS ,
second have two entry for ADDRESS.

IBA11DB=(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=first-dr-scan)(PORT=1521))(CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=IBA11DB)))
Second TNS entry with two ADDRESS
IBA11DB_W=(DESCRIPTION_LIST=(LOAD_BALANCE=off)(FAILOVER=on)  (DESCRIPTION=(CONNECT_TIMEOUT=10)(RETRY_COUNT=1)(ADDRESS_LIST=(LOAD_BALANCE=on)(ADDRESS=(PROTOCOL=TCP)(HOST=first-dr-scan.labcenter.priv)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=IBA11DB))) (DESCRIPTION=(CONNECT_TIMEOUT=10)(RETRY_COUNT=1)(ADDRESS_LIST=LOAD_BALANCE=on)(ADDRESS=(PROTOCOL=TCP)(HOST=secon-dr-scan.labcenter.priv)(PORT=1521)))(CONNECT_DATA=SERVICE_NAME=IBA11DB))))



2.  exit3.sql contain "exit". this is to simulate logon and logout. this approach is use for simplicity.
strace -fc -o test_IBA11DB_W.strace sqlplus system/xxxxxxxxx@IBA11DB_W  @exit3.sql
strace -fc -o test_IBA11DB.strace sqlplus system/xxxxxxxxx@IBA11DB  @exit3.sql
see result below.
comparing the time of connection (+ disconnection). the first connection took 175 microseconds, second with two ADDRESS took 1176 microseconds, almost 7 times slower than the IBA11DB.


3. checking the detail of strace, there are calls on the second ADDRESS.
sendto transmitted message to secon-dr-scan (second ADDRESS)
connect - initiated connection to the second IP ADDRESS
recvfrom() used to to receive messages from a socket

$cat test__verbose_IBA11DB_W.strace

21857 sendto(9, "\303\246\1\0\0\1\0\0\0\0\0\0\Rsecon-dr-scan\titsmt"..., 46, MSG_NOSIGNAL, NULL, 0) = 46
21857 poll([{fd=9, events=POLLIN}], 1, 5000) = 1 ([{fd=9, revents=POLLIN}])
21857 ioctl(9, FIONREAD, [185])         = 0
21857 recvfrom(9, "\303\246\205\200\0\1\0\3\0\2\0\2\Rsecon-dr-scan\titsmt"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.2.27.1")}, [16]) = 185
21857 poll([{fd=9, events=POLLOUT}], 1, 4999) = 1 ([{fd=9, revents=POLLOUT}])
21857 sendto(9, "R\317\1\0\0\1\0\0\0\0\0\0\Rsecon-dr-scan\titsmt"..., 46, MSG_NOSIGNAL, NULL, 0) = 46
21857 poll([{fd=9, events=POLLIN}], 1, 4999) = 1 ([{fd=9, revents=POLLIN}])
21857 ioctl(9, FIONREAD, [104])         = 0
21857 recvfrom(9, "R\317\205\200\0\1\0\0\0\1\0\0\Rsecon-dr-scan\titsmt"..., 65536, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.2.27.1")}, [16]) = 104
….


even thou the first ADDRESS in the ADDRESS_LIST is same IBA11DB and LOAD_BALANCE=off, according to oracle doc it should check the first address before trying the connecting to next ADDRESS.

But as show in the strace, oracle issues system call such as "connect", probing the second ADDRESS, even when the first is available.



/TNS_TEST>>cat test_IBA11DB.strace
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 73.71    0.000129           1       162         2 read
 14.29    0.000025           6         4           recvfrom
 12.00    0.000021           0       106        19 open
  0.00    0.000000           0        32           write
  0.00    0.000000           0        97           close
  0.00    0.000000           0         7         3 stat
  0.00    0.000000           0        69           fstat
  0.00    0.000000           0        10           poll
  0.00    0.000000           0        42           lseek
  0.00    0.000000           0        99           mmap
  0.00    0.000000           0        25           mprotect
  0.00    0.000000           0        54           munmap
  0.00    0.000000           0        15           brk
  0.00    0.000000           0        42           rt_sigaction
  0.00    0.000000           0         5           rt_sigprocmask
  0.00    0.000000           0         5           ioctl
  0.00    0.000000           0        17        10 access
  0.00    0.000000           0        13         1 socket
  0.00    0.000000           0        18         6 connect
  0.00    0.000000           0         6           sendto
  0.00    0.000000           0         4           recvmsg
  0.00    0.000000           0         2           bind
  0.00    0.000000           0        10           getsockname
  0.00    0.000000           0         6           setsockopt
  0.00    0.000000           0         6           getsockopt
  0.00    0.000000           0         1           execve
  0.00    0.000000           0        14           uname
  0.00    0.000000           0        19           fcntl
  0.00    0.000000           0         2           getdents
  0.00    0.000000           0         6           getcwd
  0.00    0.000000           0         1           readlink
  0.00    0.000000           0         5           getrlimit
  0.00    0.000000           0         4           times
  0.00    0.000000           0        10           getuid
  0.00    0.000000           0         1           getppid
  0.00    0.000000           0         2           statfs
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         2           setrlimit
  0.00    0.000000           0         5         1 futex
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00    0.000175                   931        42 total


TNS_TEST>>cat test_IBA11DB_W.strace
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 87.84    0.001033           6       165         2 read
  3.23    0.000038           0       110        19 open
  3.15    0.000037           0       103           mmap
  1.62    0.000019           1        34           write
  1.53    0.000018           3         7         3 stat
  1.36    0.000016           1        20           times
  1.28    0.000015           0        42           rt_sigaction
  0.00    0.000000           0       101           close
  0.00    0.000000           0        73           fstat
  0.00    0.000000           0        15           poll
  0.00    0.000000           0        42           lseek
  0.00    0.000000           0        25           mprotect
  0.00    0.000000           0        58           munmap
  0.00    0.000000           0        14           brk
  0.00    0.000000           0         5           rt_sigprocmask
  0.00    0.000000           0         5           ioctl
  0.00    0.000000           0        17        10 access
  0.00    0.000000           0        13         1 socket
  0.00    0.000000           0        18         6 connect
  0.00    0.000000           0         6           sendto
  0.00    0.000000           0         4           recvfrom
  0.00    0.000000           0         4           recvmsg
  0.00    0.000000           0         2           bind
  0.00    0.000000           0        11           getsockname
  0.00    0.000000           0         2           setsockopt
  0.00    0.000000           0         8         4 getsockopt
  0.00    0.000000           0         1           execve
  0.00    0.000000           0        22           uname
  0.00    0.000000           0        15           fcntl
  0.00    0.000000           0         2           getdents
  0.00    0.000000           0         6           getcwd
  0.00    0.000000           0         1           readlink
  0.00    0.000000           0         5           getrlimit
  0.00    0.000000           0        14           getuid
  0.00    0.000000           0         1           getppid
  0.00    0.000000           0         2           statfs
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         2           setrlimit
  0.00    0.000000           0         5         1 futex
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00    0.001176                   983        46 total

Summary: if application is had issue with connection to database, using two “ADDRESS” will even make it worst. Of cos, better design such as connection pooling can be deployed to alleviate this overhead. The degree of difference depends network latency between  ADDRESS and the client.

Friday, November 3, 2017

Fixed for Materialized View slow refresh or hangs (1)


Fixed for  Materialized View slow refresh or hangs.

 I did a performance tuning on a database where the application developer, literally are solving all performance problems with materialized views!?.
redo log switch occurs 300 times within an hour because 5 minute interval of COMPLETE refresh.
FAST refresh was not use because its hangs. the following highlights how issue was resolved MV slow refresh or hangs.

Lock MV log statistics immediately after creation and  alter system set "_mv_refresh_use_stats"=FALSE;
See Doc ID 420040.1
  1. this is what Explain plan of materialized view refresh look like this before above recommendation was applied.
--------------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time | Pstart| Pstop |
--------------------------------------------------------------------------------------------------------------------------------------------------
| 0 | INSERT STATEMENT | | | | | 4948M(100)| | | |
| 1 | LOAD TABLE CONVENTIONAL | MVIEW_EVOLUTION_SUMMARY_DATA | | | | | | | |
| 2 | FILTER | | | | | | | | |
| 3 | NESTED LOOPS OUTER | | 1352K| 167M| | 78593 (1)| 00:00:04 | | |
| 4 | NESTED LOOPS OUTER | | 1352K| 136M| | 78591 (1)| 00:00:04 | | |
| 5 | NESTED LOOPS OUTER | | 1352K| 107M| | 78590 (1)| 00:00:04 | | |
| 6 | HASH JOIN RIGHT OUTER | | 1352K| 77M| | 78589 (1)| 00:00:04 | | |
| 7 | VIEW | | 12840 | 426K| | 70990 (1)| 00:00:03 | | |
| 8 | HASH JOIN SEMI | | 12840 | 2156K| 293M| 70982 (1)| 00:00:03 | | |
| 9 | TABLE ACCESS FULL | APP_INCREA_EVENT | 6679K| 216M| | 52261 (1)| 00:00:03 | | |
| 10 | TABLE ACCESS FULL | MLOG$_APP_INCREA_EVENT | 20545 | 2768K| | 4028 (1)| 00:00:01 | | |
| 11 | TABLE ACCESS FULL | APP_TRANSACTION | 1352K| 33M| | 7595 (1)| 00:00:01 | | |
| 12 | TABLE ACCESS BY GLOBAL INDEX ROWID| APP_INCOMES_QUALIFICATION | 1 | 23 | | 1 (0)| 00:00:01 | ROWID | ROWID |
| 13 | INDEX UNIQUE SCAN | APP_INCOMES_QUALIFICATION_PK | 1 | | | 0 (0)| | | |
| 14 | TABLE ACCESS BY GLOBAL INDEX ROWID | APP_INCOMES_QUALIFICATION | 1 | 23 | | 1 (0)| 00:00:01 | ROWID | ROWID |
| 15 | INDEX UNIQUE SCAN | APP_INCOMES_QUALIFICATION_PK | 1 | | | 0 (0)| | | |
| 16 | TABLE ACCESS BY GLOBAL INDEX ROWID | APP_INCOMES_CUSTOMER | 1 | 24 | | 2 (0)| 00:00:01 | ROWID | ROWID |
| 17 | INDEX UNIQUE SCAN | APP_INCOMES_CUSTOMER_PK | 1 | | | 1 (0)| 00:00:01 | | |
| 18 | FILTER | | | | | | | | |
| 19 | MAT_VIEW ACCESS FULL | MVIEW_EVOLUTION_SUMMARY_DATA | 1 | 10 | | 3663 (1)| 00:00:01 | | |
| 20 | FILTER | | | | | | | | |
| 21 | NESTED LOOPS | | 1 | 24 | | 3 (0)| 00:00:01 | | |
| 22 | TABLE ACCESS BY USER ROWID | APP_TRANSACTION | 1 | 18 | | 1 (0)| 00:00:01 | | |
| 23 | INDEX RANGE SCAN | INCREA_EVENT_2_TRANSACTION_IDX | 1 | 6 | | 2 (0)| 00:00:01 | | |
--------------------------------------------------------------------------------------------------------------------------------------------------
Note
-----
- dynamic statistics used: dynamic sampling (level=2)

  1. if MV log exist, drop and recreate.
  1.   drop materialized view log on crs_change_event;
  2.   CREATE MATERIALIZED VIEW LOG ON USERS_APP.APP_INCREA_EVENT TABLESPACE "APP_TBS"
  2. gather statistics on MV LOGS and lock the statisctics.
  1. exec DBMS_STATS.gather_TABLE_STATS('USERS_APP','MLOG$_APP_INCREA_EVENT',force=>true);
  2. exec DBMS_STATS.LOCK_TABLE_STATS('USERS_APP','MLOG$_APP_INCREA_EVENT');

3. alter system
  1.  alter system set "_mv_refresh_use_stats"=FALSE;

4. create MV
  1. CREATE MATERIALIZED VIEW "USERS_APP"."MVIEW_EVOLUTION_SUMMARY_DATA".....

After the remommedation. you can see a signficant improvement in the Cost section of both plans. and it using an hash join instead of a nested loops.

----------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------------------------
| 0 | INSERT STATEMENT | | | | | 100K(100)| | | |
| 1 | LOAD TABLE CONVENTIONAL | MVIEW_EVOLUTION_SUMMARY_DATA | | | | | | | |
| 2 | HASH JOIN RIGHT OUTER | | 6532K| 809M| | 100K (1)| 00:00:04 | | |
| 3 | PARTITION LIST ALL | | 44179 | 992K| | 248 (1)| 00:00:01 | 1 | 3 |
| 4 | TABLE ACCESS FULL | APP_INCOMES_QUALIFICATION | 44179 | 992K| | 248 (1)| 00:00:01 | 1 | 3 |
| 5 | HASH JOIN RIGHT OUTER | | 6532K| 666M| | 100K (1)| 00:00:04 | | |
| 6 | PARTITION LIST ALL | | 44179 | 992K| | 248 (1)| 00:00:01 | 1 | 3 |
| 7 | TABLE ACCESS FULL | APP_INCOMES_QUALIFICATION | 44179 | 992K| | 248 (1)| 00:00:01 | 1 | 3 |
| 8 | HASH JOIN RIGHT OUTER| | 6532K| 523M| 220M| 100K (1)| 00:00:04 | | |
| 9 | PARTITION LIST ALL | | 6426K| 147M| | 33553 (1)| 00:00:02 | 1 | 3 |
| 10 | TABLE ACCESS FULL | APP_INCOMES_CUSTOMER | 6426K| 147M| | 33553 (1)| 00:00:02 | 1 | 3 |
| 11 | HASH JOIN OUTER | | 6532K| 373M| 49M| 33239 (1)| 00:00:02 | | |
| 12 | TABLE ACCESS FULL | APP_TRANSACTION | 1352K| 33M| | 2065 (1)| 00:00:01 | | |
| 13 | TABLE ACCESS FULL | APP_INCREA_EVENT | 6679K| 216M| | 14184 (1)| 00:00:01 | | |
----------------------------------------------------------------------------------------------------------------------------------


5.  Query dba_mviews to check the staleness.
  1. select a.LAST_REFRESH_DATE,a.staleness,a.after_fast_refresh,a.MVIEW_NAME from dba_mviews a where owner='USERS_APP'

  1. LAST_REFRESH_DATE   STALENESS AFTER_FAST_REFRESH  MVIEW_NAME
  2. ------------------- ------------------- ------------------- --------------------------------------------------------------------------------------------------------------------------------
  3. 2017-08-26 13:37:37 FRESH FRESH    MVIEW_EVOLUTION_SUMMARY_DATA 
  4.   
  5.   


Version: 12.1