01 November, 2008

Numbers and NULLs

In a recent forums.oracle.com thread I had mistakenly stated that "Therefore, even if 1 row out of a million rows has a NULL, you'd get a SUM result as a NUL" after correctly asserting that "Adding a value to a NULL returns a NULL." I did point out later that although SUM (and AVG) ignores NULLs, a COUNT(*) doesnt.Link

Here is a test case about
a) how Average != Sum/Count if any of the rows contains a NULL.
b) how adding a NULL to a number returns a NULL (and adding a number to a NULL still returns a NULL !)


SQL>
SQL> drop table test_sum_numbers purge;

Table dropped.

SQL>
SQL> REM COL_2 has a NULL in one of 4 rows
SQL> create table test_sum_numbers (col_1 number, col_2 number);

Table created.

SQL> insert into test_sum_numbers values (10, 10);

1 row created.

SQL> insert into test_sum_numbers values (20, 20);

1 row created.

SQL> insert into test_sum_numbers values (30, NULL);

1 row created.

SQL> insert into test_sum_numbers values (40, 40);

1 row created.

SQL> commit;

Commit complete.

SQL>
SQL> REM Here we see that SUM/COUNT != AVG because the SUM excluded NULLs but the COUNT of all rows includes NULLs
SQL> select count(*) Num_Rows, sum(col_1) Total_1, avg(col_1) Avg_1, sum(col_2) Total_2, avg(col_2) Avg_2 from test_sum_numbers ;

NUM_ROWS TOTAL_1 AVG_1 TOTAL_2 AVG_2
---------- ---------- ---------- ---------- ----------
4 100 25 70 23.3333333

SQL>
SQL> REM Here we see that we can "adjust" NULLs to 0 so that SUM/COUNT == AVG
SQL> select count(*) Num_Rows, sum(nvl(col_1,0)) Total_1, avg(nvl(col_1,0)) Avg_1, sum(nvl(col_2,0)) Total_2, avg(nvl(col_2,0)) Avg_2 from test_sum_numbers ;

NUM_ROWS TOTAL_1 AVG_1 TOTAL_2 AVG_2
---------- ---------- ---------- ---------- ----------
4 100 25 70 17.5

SQL>
SQL>
SQL> REM What happens if we were to add two sets of columns from two tables ?
SQL> select CNT_1 + CNT_2 Total_Rows, SC_1 + SC_2 Total_Sum, (SC_1+SC_2)/(CNT_1+CNT_2) Is_this_the_Average
2 from
3 (select count(*) CNT_1, sum(col_1) SC_1 from test_sum_numbers table_a),
4 (select count(*) CNT_2, sum(col_2) SC_2 from test_sum_numbers table_b)
5 /

TOTAL_ROWS TOTAL_SUM IS_THIS_THE_AVERAGE
---------- ---------- -------------------
8 170 21.25

SQL>
SQL> REM What happens if we ADD the values for each of the rows
SQL> set serveroutput on size 10000
SQL> variable i number;
SQL>
SQL> declare
2 cursor fetch_cursor is select col_1 from test_sum_numbers;
3 c1 number;
4 agg_1 number;
5 cnv_agg_1 number;
6 begin
7 agg_1 := 0;
8 open fetch_cursor ;
9 loop
10 fetch fetch_cursor into c1;
11 exit when fetch_cursor%NOTFOUND;
12 agg_1 := agg_1 + c1;
13 end loop;
14 dbms_output.put_line('Sum of col_1 is ' agg_1);
15 cnv_agg_1 := nvl(agg_1,0);
16 dbms_output.put_line('Testing agg_1 for NULL : ' cnv_agg_1);
17 end;
18 /
Sum of col_1 is 100
Testing agg_1 for NULL : 100

PL/SQL procedure successfully completed.

SQL>
SQL> declare
2 cursor fetch_cursor is select col_2 from test_sum_numbers;
3 c2 number;
4 agg_2 number;
5 cnv_agg_2 number;
6 begin
7 agg_2 := 0;
8 open fetch_cursor ;
9 loop
10 fetch fetch_cursor into c2;
11 exit when fetch_cursor%NOTFOUND;
12 agg_2 := agg_2 + c2;
13 end loop;
14 dbms_output.put_line('Sum of col_2 is ' agg_2);
15 cnv_agg_2 := nvl(agg_2,0);
16 dbms_output.put_line('Testing agg_2 for NULL : ' cnv_agg_2);
17 end;
18 /
Sum of col_2 is
Testing agg_2 for NULL : 0

PL/SQL procedure successfully completed.

SQL>
SQL> REM So the addition in col_2 returned a NULL ? Let's check it again
SQL>
SQL> declare
2 cursor fetch_cursor is select col_2 from test_sum_numbers order by col_1;
3 c2 number;
4 agg_2 number;
5 cnv_agg_2 number;
6 begin
7 agg_2 := 0;
8 dbms_output.put_line ('Begin aggregation at :' agg_2);
9 open fetch_cursor ;
10 loop
11 fetch fetch_cursor into c2;
12 exit when fetch_cursor%NOTFOUND;
13 dbms_output.put_line('Have read value 'c2);
14 agg_2 := agg_2 + c2;
15 dbms_output.put_line('The aggregation is now : ' agg_2);
16 end loop;
17 dbms_output.put_line('Sum of col_2 is ' agg_2);
18 cnv_agg_2 := nvl(agg_2,0);
19 dbms_output.put_line('Testing agg_2 for NULL : ' cnv_agg_2);
20 end;
21 /
Begin aggregation at :0
Have read value 10
The aggregation is now : 10
Have read value 20
The aggregation is now : 30
Have read value
The aggregation is now :
Have read value 40
The aggregation is now :
Sum of col_2 is
Testing agg_2 for NULL : 0

PL/SQL procedure successfully completed.

SQL>
SQL> REM Addition of the col_2 value was running fine till it hit a NULL
SQL> REM The result of adding a number to a NULL was a NULL
SQL> REM Adding numbers to it after that still kept returning NULL


As robert has clarified in his comment, if I did a select count(col_2) it would ignore the NULL. Therefore, while a count(*) returns 4, a count(col_2) returns 3 (and count(col_1) -- all being NOT NULL values -- returns 4).


19 October, 2008

Using STATISTICS_LEVEL='ALL' and 10046, level 8

Although I have, on occassion, used event 10046, level 8 to trace database operations in production, I am taken aback when a vendor wants to use both STATISTICS_LEVEL='ALL' and 10046, level 8 together for a long-running job ostensibly to collect more detailed information.

I can understand STATISTICS_LEVEL='ALL' providing better information in V$ views. But does it provide "better" information when the reviewing only AWR reports and tkprof outputs of the trace files (gathered with event 10046, level 8) ? I am not convinced of the need for this in production.

I have decided to run a simple test with an UPDATE statement on a 10million row table.
One run will be with STATISTICS_LEVEL='TYPICAL' and tracing with event 10046 set at level 1.
The second run will be with STATISTICS_LEVEL='ALL' and tracing with event 10046 set at level 8.

FIRST RUN, with STATISTICS_LEVEL='TYPICAL' and Level 1 Tracing :

update my_transactions mt
set mt.converted_amount =
(select st.transaction_amount*sf.conv_rate
from my_transactions st, my_fx_rates sf
where
st.transaction_c_c=sf.currency_code
and
trunc(st.transaction_date)=sf.conv_rate_date
and
st.transaction_id=mt.transaction_id),
mt.updated_at=sysdate

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.03 0.03 0 0 0 0
Execute 1 1074.94 1184.89 753724 62611107 10743805 10000000
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 1074.98 1184.93 753724 62611107 10743805 10000000

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 64

Rows Row Source Operation
------- ---------------------------------------------------
0 UPDATE MY_TRANSACTIONS (cr=60928473 pr=742011 pw=0 time=1157314862 us)
20338218 TABLE ACCESS FULL MY_TRANSACTIONS (cr=10979090 pr=732914 pw=0 time=183093956 us)
10278974 NESTED LOOPS (cr=51631852 pr=20663 pw=0 time=715168290 us)
10338218 TABLE ACCESS BY INDEX ROWID MY_TRANSACTIONS (cr=31014657 pr=20469 pw=0 time=305940011 us)
10338218 INDEX UNIQUE SCAN MY_TRANSACTIONS_PK (cr=20676439 pr=20469 pw=0 time=163468271 us)(object id 58495)
10278974 TABLE ACCESS BY INDEX ROWID MY_FX_RATES (cr=20617195 pr=194 pw=0 time=256486318 us)
10278974 INDEX UNIQUE SCAN MY_FX_RATES_PK (cr=10338221 pr=119 pw=0 time=124931227 us)(object id 58464)

********************************************************************************


SECOND RUN, with STATISTICS_LEVEL='ALL' and Level 8 Tracing :


update my_transactions mt
set mt.converted_amount =
(select st.transaction_amount*sf.conv_rate
from my_transactions st, my_fx_rates sf
where
st.transaction_c_c=sf.currency_code
and
trunc(st.transaction_date)=sf.conv_rate_date
and
st.transaction_id=mt.transaction_id),
mt.updated_at=sysdate

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.02 0.03 0 0 0 0
Execute 1 1165.17 1261.06 753135 62114208 10724083 10000000
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 1165.20 1261.10 753135 62114208 10724083 10000000

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 64

Rows Row Source Operation
------- ---------------------------------------------------
0 UPDATE MY_TRANSACTIONS (cr=60933001 pr=744851 pw=0 time=1240297420 us)
20239080 TABLE ACCESS FULL MY_TRANSACTIONS (cr=10975891 pr=732493 pw=0 time=222679174 us)
10179836 NESTED LOOPS (cr=51136162 pr=20449 pw=0 time=716122504 us)
10239080 TABLE ACCESS BY INDEX ROWID MY_TRANSACTIONS (cr=30717243 pr=20259 pw=0 time=308789524 us)
10239080 INDEX UNIQUE SCAN MY_TRANSACTIONS_PK (cr=20478163 pr=20259 pw=0 time=167672057 us)(object id 58495)
10179836 TABLE ACCESS BY INDEX ROWID MY_FX_RATES (cr=20418919 pr=190 pw=0 time=255736454 us)
10179836 INDEX UNIQUE SCAN MY_FX_RATES_PK (cr=10239083 pr=115 pw=0 time=125362994 us)(object id 58464)


Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 107600 0.07 56.46
db file scattered read 40467 0.26 65.70
log file switch completion 171 0.17 3.42
log buffer space 3 0.04 0.12
log file switch (checkpoint incomplete) 5 0.97 1.06
latch: cache buffers lru chain 152 0.00 0.01
rdbms ipc reply 221 0.03 0.11
latch: object queue header operation 11 0.10 0.10
latch: checkpoint queue latch 1 0.00 0.00
buffer busy waits 2 0.00 0.01
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.03 0.03
********************************************************************************


The execution time was only slightly higher at 1,261seconds versus 1,185seconds. However, I also note that, other than the listing of Wait Events and durations of each event, I do not notice information in the tkprof output of the trace file when I review it post-facto.
STATISTICS_LEVEL='ALL' does provide additional information in V$ views but that is unlikely to be visible in a tkprof of an SQL Trace file (whether level 1 or 8) that is generated and reviewed later.

12 October, 2008

Delayed Block Cleanout -- through Instance Restart

Continuing my previous post on Delayed Block Cleanout, in this post, I show how a database shutdown doesn't guarantee that all the modified blocks in a table are "cleaned out" before the shutdown.

I run a large update and commit it. Next, I shutdown the database. The first query against the table after the subsequent restart still has to examine modified blocks, confirm if the updates to rows in the block have been committed and then execute a cleanout of these modified blocks. Thus, we see "consistent gets - examination" and "cleanout%" statistics being incremented for the first query after the restart :


SQL> select blocks,num_rows from user_tables where table_name = upper('test_d_b_c');

BLOCKS NUM_ROWS
---------- ----------
47069 3242752

SQL> SELECT COUNT(*) FROM TEST_D_B_C;

COUNT(*)
----------
3242752

SQL> @Report_select_Statistics
SQL> set echo off

Statistic Value
---------------------------------------------------------- ----------------
cleanout - number of ktugct calls 0
cleanouts and rollbacks - consistent read gets 0
cleanouts only - consistent read gets 0
consistent changes 0
consistent gets 47,513
consistent gets - examination 207
db block changes 0
db block gets 0
redo entries 0
redo size 0
undo change vector size 0
SQL>
SQL> REM Run an update on 60% (not all) of the rows
SQL> UPDATE TEST_D_B_C SET COL_1 = 'HKC_'||SUBSTR(COL_1,4,11) WHERE MOD(COL_4,10) > 3 ;

1945344 rows updated.

SQL> COMMIT;

Commit complete.

SQL>
SQL> REM We will now shutdown and restart the database
SQL> connect / as sysdba
Connected.
SQL> shutdown immediate
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup
ORACLE instance started.

Total System Global Area 734003200 bytes
Fixed Size 2023688 bytes
Variable Size 264244984 bytes
Database Buffers 461373440 bytes
Redo Buffers 6361088 bytes
Database mounted.
Database opened.
SQL>
SQL> connect hemant/hemant
Connected.
SQL> REM Now let's query the table
SQL> REM Will the first execution suffer delayed block cleanout ?
SQL>
SQL> SELECT COUNT(*) FROM TEST_D_B_C;

COUNT(*)
----------
3242752

SQL> @Report_select_Statistics
SQL> set echo off

Statistic Value
---------------------------------------------------------- ----------------
cleanout - number of ktugct calls 46,969
cleanouts and rollbacks - consistent read gets 0
cleanouts only - consistent read gets 46,969
consistent changes 0
consistent gets 94,910
consistent gets - examination 47,367
db block changes 46,973
db block gets 3
redo entries 46,971
redo size 3,383,012
undo change vector size 204
SQL>
SQL> SELECT COUNT(*) FROM TEST_D_B_C;

COUNT(*)
----------
3242752

SQL> @Report_select_Statistics
SQL> set echo off

Statistic Value
---------------------------------------------------------- ----------------
cleanout - number of ktugct calls 46,969
cleanouts and rollbacks - consistent read gets 0
cleanouts only - consistent read gets 46,969
consistent changes 0
consistent gets 141,993
consistent gets - examination 47,367
db block changes 46,973
db block gets 3
redo entries 46,971
redo size 3,383,012
undo change vector size 204


It is the first full table scan query that shows "consistent gets - examination" and "cleanout%" statistics. It did 46,969 examinations and cleanouts and generated 3.383MB of redo (for the correspondng 46,971 redo entries).