Tuesday, January 30, 2007

If it could all possibly go wrong...

If it could all possibly go wrong... it did.

I upgraded one of my databases from 9.2.0.7 to 10.2.0.2 this past weekend. What normally should have taken about 2 hours took 9. Everything that could have possibly gone wrong with an upgrade did, and I’m just glad that I was able to finally get it done and open for business without having to recover it and go back to the drawing board. For those of you who are still in the 9i world and are going to be upgrading here in the future please for God’s sake bookmark this blog entry or the Metalink notes provided. Maybe it will save you, maybe it wont….

It all started by using the DBUA. I was directed to use this wonderful and fantastic tool instead of manually doing it. Someone thinks watching a progress bar is much cooler than watching code go flying by.

According to the DBUA and associated logs after the upgrade everything was just dandy! I shut the database down poked around a bit giving myself a peace of mind then fired it backup.

BAM!
ORA-00604: error occurred at recursive SQL levelError 604 happened during db open, shutting down database

USER: terminating instance due to error 604Instance terminated by USER, pid = 13418
ORA-1092 signalled during: ALTER DATABASE OPEN

I spent the next 30 minutes trying everything I could think of as well as scouring Metalink for some kind of clue as to what was causing this. I came up with Nada, zip, nothing! I had to break down and open up a case with Oracle. After sending them all the logs and explanations, they came back with “go run the catupgrd.sql” script and see if it fixes it. Why, I have no clue but it fixed the problem and I was able to open the database.

Database is open all looks well, ok time to enable the database jobs (mainly my stats pack job).

BAM!
ORA-12899: value too large for column "PERFSTAT"."STATS$SGASTAT"."POOL"(actual: 12, maximum: 11)
ORA-06512: at "PERFSTAT.STATSPACK", line 2065ORA-06512: at PERFSTAT.STATSPACK", line 91ORA-06512: at line 1
WARNING: Detected too many memory locking problems.WARNING: Performance degradation may occur.

I figured the easy fix for this one was to simply go in and blow away perfstat and recreate him again. New database, new stats hmmm why not? Confirmed with Oracle since I still had the case open with them and they confirmed that that was the best course of action as well. $ORACLE_HOME/rdbms/admin/spdrop.sql $ORACLE_HOME/rdbms/admin/spcreate.sql easy enough.

Ok, Database is up Perfstat is fixed no errors in the alertlog, jobs are enabled, alright lets go ahead start the listener and let some feeds come in.

BAM!
ORA-04065: not executed, altered or dropped stored procedure"PUBLIC.DBMS_OUTPUT"ORA-06508: PL/SQL: could not find program unit being called:"PUBLIC.DBMS_OUTPUT"

Ohhh this is a good one. Apparently according to Metalink this error occurs because this package got its memory status broken at some point in time. When the package is recompiled, this status is cleared but (big but) the situation can still occur. The way to fix this issue is to run the utlirp.sql (not to be confused with the utlrp.sql) Check out Metalink note 370137.1 and it will explain it all.


Alright, utlirp.sql has been ran database got bounced (again) everything is looking good, feeds look good. Everything is satisfactory let’s back this puppy up.

BAM!

RMAN-03009: failure of backup command on ORA_DISK_3 channel
RMAN-10038: database session for channel ORA_DISK_3 terminated unexpectedly
channel ORA_DISK_3 disabled, job failed on it will be run on another channel

ORA-07445: exception encountered: core dump [memcpy()+40] [SIGSEGV] [Address not mapped to object] [0x000000000] [] []

This is caused because the Controlfile autobackup parameter is off in the RMAN configuration. A nifty little bug, Check out note 399395.1 for details.

The parameter is in the “on” position… back the database up……. Good backup.! Let’s open her up for business!!

Next morning I come in check the alert log ok, ok, good, uhh huuu,…
BAM!
ORA-00054: resource busy and acquire with NOWAIT specified
ORA-06512: at "SYS.DBMS_STATS", line 13313
ORA-06512: at "SYS.DBMS_STATS", line 13659
ORA-06512: at "SYS.DBMS_STATS", line 13737
ORA-06512: at "SYS.DBMS_STATS", line 13696
ORA-06512: at "SYSTEM.DB_SCHEMA_STATS", line 7
ORA-06512: at line 1

Another bug only thing is I’m kind of confused because the note says 10.2.0.1.0 and we went to 10.2.0.2. Also it says the only way to analyze the object(s) in question is to do it during next scheduled maintenance or gather the stats before any refresh operation. Uhh sorry to tell you guys but I need to run stats at least twice a week with the amount of transactions I’m doing, and my refresh job runs like every 5 minutes. Got to think of an alternative. Note:377183.1


I’m done..think I’m going to go and take my aggressions out and play some World of Warcraft.

Y2K All over again

Does anybody else feel like it's 1999 again with all these DST fixes that have to go in?

Tuesday, January 23, 2007

dizwell.com


I can always tell when HJR changes something on dizwell.com. This time I broke the record and got five copies of every post for the last two weeks through the RSS feed. During October "upgrade" I only got three. Looks like things have calmed down, down under.


Powered by Zoundry

Friday, January 19, 2007

Cookbooks


I'm a big fan of what I call cookbooks. Cookbooks are step-by-step directions that if followed, will yield the desired result. In fact, most of my cookbooks are copy & past enabled so that you copy a command from the cookbook and paste it into your window to execute the command. I insist my people use these established methods where available and I get pretty ticked off when they waste a lot of time trying to figure out what has already been learned.


I've installed Oracle on Linux about 50 times over the past few months. After the second succesfull install, I created a cookbook for both 9i and 10g. If followed exactly, any DBA will be able to install Oracle correctly in my environment. I created the cookbook and I know it like the back of my hand. I don't need no stinkin cookbook and proceeded to do a fresh install of 9.2.0.8 when the installer hangs at 18% linking naeet.o.


"Hmm, must be somthing wrong with Linux", I thought to myself.


I checked that the correct versions of gcc and g++ were in my path. I knew I set LD_ASSUME_KERNEL so I didn't have to check that. Then I looked at metlink and found a note that said my LD_ASSUME_KERNEL had to be 2.4.19, which I already knew I set, so that couldn't be it.


I poked around at some other things before going back to my cookbook.


Kernel parameters, check.


ORACLE_HOME set, check.


LD_ASSUME_KERNEL, I know I set that, skip it.


Correct version of gcc and g++, check.


Reran the installer and it hung again at 18%.


The only thing I didn't double check was LD_ASSUME_KERNEL. So I see what's in the environment variable, and lo and behold, it's not set. Seems I set LD_ASSUMEKERNEL instead of LD_ASSUME_KERNEL.


I've sent a stern email to myself about not following process. If I do it again, I'll be fired.


Powered by Zoundry

Friday, January 12, 2007

Jonathan Lewis is one smart dude

First, let me say that Jonathan Lewis has helped me immensely on my optimizer problem (here, here, and here). Without his help, I'd still be banging my head against a brick wall and arguing with Oracle Support as to why I need to upgrade to 10.2.0.3. A hundred thank you's, Jonathan. (I hope this doesn't land me on the "dummy list" of the next Scratchpad post)

Back to my optimizer issue, I should have known the plan was cached.

Let me take that back, I knew the plan was cached, but assumed (I know, I know) that the 10195 event would require a hard parse again. In retrospect, that was a silly thought, but seemed logical in the heat of battle. Anyway, the 10195 event does indeed turn off predicate generation for check constraints. Updated script and results to follow.

It still begs the question as to why Oracle evaluates the constraints this way (other than the response I got from Oracle Support "that's the way it works"), but at least we have a way out now.


Script:

set timing on
set echo on;
alter system flush shared_pool;
drop table t1;
create table t1 (
id number primary key,
date_matched date,
other_stuff varchar2(222),
constraint ck1 check (date_matched = trunc(date_matched))
);
drop table t2;
create table t2 (
id number primary key,
date_matched date,
other_stuff varchar2(222)
);
declare
dm date;
dc integer := 0;
begin
for i in 1..100000 loop
if mod(i,10) = 0 then
dm := trunc(sysdate + mod(dc,66));
dc := dc+1;
else
dm := to_date('12/31/4712','mm/dd/yyyy');
end if;
insert into t1 values (i, dm, rpad('x',mod(i,222)));
insert into t2 values (i, dm, rpad('x',mod(i,222)));
end loop;
commit;
dbms_stats.gather_table_stats(
ownname=>USER,
tabname=>'T1',
cascade=>true,
estimate_percent=>NULL);
dbms_stats.gather_table_stats(
ownname=>USER,
tabname=>'T2',
cascade=>true,
estimate_percent=>NULL);
end;
/
create index t1_dm on t1(date_matched);
create index t2_dm on t2(date_matched);

select * from v$version;

-- here's the explain plan before 10195 event
explain plan for select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);
explain plan for select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);

alter session set events '10195 trace name context forever, level 1';

-- here's the explain plan after
explain plan for select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);
explain plan for select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);

-- set the 10195 event off for now
alter session set events '10195 trace name context off';

-- lets get some blocks in cache
select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

-- lets time one with tkprof
alter session set tracefile_identifier = 't1t2';
alter session set events '10046 trace name context forever, level 12';
-- add a comment to get a new plan
select /* 10195 OFF Q1 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select /* 10195 OFF Q2 */ count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select /*+ rule 10195 OFF Q3 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

-- set 10195 event on again
alter session set events '10195 trace name context forever, level 1';

-- do queries again with new comments
select /* 10195 ON Q1 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select /* 10195 ON Q2 */ count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select /*+ rule 10195 ON Q3 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

-- just for kicks, do the bad plan again
alter session set events '10195 trace name context off';
select /* 10195 OFF_AGAIN Q2 */ count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select /*+ rule 10195 OFF_AGAIN Q3 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select /* 10195 OFF_AGAIN Q1 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');


Results:

SQL> alter system flush shared_pool;

System altered.

Elapsed: 00:00:00.18
SQL> drop table t1;

Table dropped.

Elapsed: 00:00:00.97
SQL> create table t1 (
2 id number primary key,
3 date_matched date,
4 other_stuff varchar2(222),
5 constraint ck1 check (date_matched = trunc(date_matched))
6 );

Table created.

Elapsed: 00:00:00.06
SQL> drop table t2;

Table dropped.

Elapsed: 00:00:00.05
SQL> create table t2 (
2 id number primary key,
3 date_matched date,
4 other_stuff varchar2(222)
5 );

Table created.

Elapsed: 00:00:00.03
SQL> declare
2 dm date;
3 dc integer := 0;
4 begin
5 for i in 1..100000 loop
6 if mod(i,10) = 0 then
7 dm := trunc(sysdate + mod(dc,66));
8 dc := dc+1;
9 else
10 dm := to_date('12/31/4712','mm/dd/yyyy');
11 end if;
12 insert into t1 values (i, dm, rpad('x',mod(i,222)));
13 insert into t2 values (i, dm, rpad('x',mod(i,222)));
14 end loop;
15 commit;
16 dbms_stats.gather_table_stats(
17 ownname=>USER,
18 tabname=>'T1',
19 cascade=>true,
20 estimate_percent=>NULL);
21 dbms_stats.gather_table_stats(
22 ownname=>USER,
23 tabname=>'T2',
24 cascade=>true,
25 estimate_percent=>NULL);
26 end;
27 /

PL/SQL procedure successfully completed.

Elapsed: 00:00:36.07
SQL> create index t1_dm on t1(date_matched);

Index created.

Elapsed: 00:00:00.34
SQL> create index t2_dm on t2(date_matched);

Index created.

Elapsed: 00:00:00.34
SQL>
SQL> select * from v$version;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Prod
PL/SQL Release 10.2.0.1.0 - Production
CORE 10.2.0.1.0 Production
TNS for Linux: Version 10.2.0.1.0 - Production
NLSRTL Version 10.2.0.1.0 - Production

Elapsed: 00:00:00.05
SQL>
SQL> -- here's the explain plan before 10195 event
SQL> explain plan for select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

Explained.

Elapsed: 00:00:00.03
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 1573756541

---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 8 | 4 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 8 | | |
|* 2 | INDEX RANGE SCAN| T1_DM | 15 | 120 | 4 (0)| 00:00:01 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
---------------------------------------------------

2 - access("DATE_MATCHED"=TO_DATE('4712-12-31 00:00:00', 'yyyy-mm-dd
hh24:mi:ss'))
filter(TRUNC(INTERNAL_FUNCTION("DATE_MATCHED"))=TO_DATE('4712-12-
31 00:00:00', 'yyyy-mm-dd hh24:mi:ss'))

17 rows selected.

Elapsed: 00:00:00.15
SQL> explain plan for select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

Explained.

Elapsed: 00:00:00.01
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 3430539338

---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 8 | 4 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 8 | | |
|* 2 | INDEX RANGE SCAN| T2_DM | 1493 | 11944 | 4 (0)| 00:00:01 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
---------------------------------------------------

2 - access("DATE_MATCHED"=TO_DATE('4712-12-31 00:00:00', 'yyyy-mm-dd
hh24:mi:ss'))

15 rows selected.

Elapsed: 00:00:00.02
SQL>
SQL> alter session set events '10195 trace name context forever, level 1';

Session altered.

Elapsed: 00:00:00.00
SQL>
SQL> -- here's the explain plan after
SQL> explain plan for select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

Explained.

Elapsed: 00:00:00.00
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 1573756541

---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 8 | 4 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 8 | | |
|* 2 | INDEX RANGE SCAN| T1_DM | 1493 | 11944 | 4 (0)| 00:00:01 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
---------------------------------------------------

2 - access("DATE_MATCHED"=TO_DATE('4712-12-31 00:00:00', 'yyyy-mm-dd
hh24:mi:ss'))

15 rows selected.

Elapsed: 00:00:00.02
SQL> explain plan for select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

Explained.

Elapsed: 00:00:00.00
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 3430539338

---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 8 | 4 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 8 | | |
|* 2 | INDEX RANGE SCAN| T2_DM | 1493 | 11944 | 4 (0)| 00:00:01 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
---------------------------------------------------

2 - access("DATE_MATCHED"=TO_DATE('4712-12-31 00:00:00', 'yyyy-mm-dd
hh24:mi:ss'))

15 rows selected.

Elapsed: 00:00:00.01
SQL>
SQL> -- set the 10195 event off for now
SQL> alter session set events '10195 trace name context off';

Session altered.

Elapsed: 00:00:00.00
SQL>
SQL> -- lets get some blocks in cache
SQL> select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.09
SQL> select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.02
SQL>
SQL> -- lets time one with tkprof
SQL> alter session set tracefile_identifier = 't1t2';

Session altered.

Elapsed: 00:00:00.00
SQL> alter session set events '10046 trace name context forever, level 12';

Session altered.

Elapsed: 00:00:00.00
SQL> -- add a comment to get a new plan
SQL> select /* 10195 OFF Q1 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.10
SQL> select /* 10195 OFF Q2 */ count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.03
SQL> select /*+ rule 10195 OFF Q3 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.02
SQL>
SQL> -- set 10195 event on again
SQL> alter session set events '10195 trace name context forever, level 1';

Session altered.

Elapsed: 00:00:00.01
SQL>
SQL> -- do queries again with new comments
SQL> select /* 10195 ON Q1 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.03
SQL> select /* 10195 ON Q2 */ count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.02
SQL> select /*+ rule 10195 ON Q3 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.03
SQL>
SQL> -- just for kicks, do the bad plan again
SQL> alter session set events '10195 trace name context off';

Session altered.

Elapsed: 00:00:00.01
SQL> select /* 10195 OFF_AGAIN Q2 */ count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.02
SQL> select /*+ rule 10195 OFF_AGAIN Q3 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.03
SQL> select /* 10195 OFF_AGAIN Q1 */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

COUNT(*)
----------
90000

Elapsed: 00:00:00.09
SQL>

Opportunity for a MySQL DBA

I am looking for a MySQL Database Administrator to join my team. The position will be located at our Greenwich, Connecticut headquarters. The ideal candidate will have a mix of database technologies, predominantly MySQL, as well as a minimum of three years experience as a Database Administrator on the Linux platform.

Responsibilities
  • Administer Backup/Recovery processes
  • Install and Configure Database Software
  • Identify and resolve performance problems.
  • Automate day-to-day tasks as needed.
  • Rotating on-duty coverage is expected.
  • Manage access to database resources

Required Skills
  • 3+ years experience as MySQL DBA in a production Linux environment.
  • 1+ years experience with MySQL 5.0.
  • 2+ years exposure to Oracle in a production or development environment.
  • Day-to-day Database Administration.
  • Backup and Recovery using InnoDB Backup, Zmanda, mysqldump.
  • MySQL Replication.
  • Ability to quickly diagnose and resolve performance using standard tools.
  • Some experience with both MySQL and Oracle partitioning.
  • Self-starter with initiative and desire to learn.
  • Ability to work quickly in a fast-paced environment.
  • Ability to communicate clearly, constructively and concisely to peers and end-users.
  • Ability to work independently with minimal supervision and drive issues to closure.

Desired Skills
  • Automation of DBA tasks (Perl, CGI, Ksh, PHP) .
  • Some experience in Oracle 10g, MySQL 5.1.
  • DR Strategies including Replication/Standby Database.
  • Supporting mission critical systems in 24x7 environment

For further consideration, candidates should send their resume, cover letter, and salary history to recruiting@interactivebrokers.com. Please indicate you are applying for the "Database Administrator" position.

Thursday, January 11, 2007

Just set the 10195 event

Going back and forth with Oracle on what I think is an optimizer problem. Thanks to JL, we pretty much have figured out what the short-term solution is, yet the nagging question is Why?

Oracle Support came up with an 10195 event (Doc: 271999.1 on ML for those interested) , which essentially disables predicate generation for check constraints. OK, fine and dandy. But it still doesn't solve our performance problem. Perhaps it's more than an optimizer problem after all. (I'll post at the end of the article the exact scripts I used to setup this example. I'd actually be interested if other people on other platforms experience this as well.)

Take for example:

SQL> alter session set events '10195 trace name context forever, level 1';

Session altered.

Elapsed: 00:00:00.01
SQL> alter session set events '10046 trace name context forever, level 12';

Session altered.

Elapsed: 00:00:00.01
SQL> explain plan for select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

Explained.

Elapsed: 00:00:00.04
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 2788119336

---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 8 | 4 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 8 | | |
|* 2 | INDEX RANGE SCAN| T1_DM | 1493 | 11944 | 4 (0)| 00:00:01 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
2 - access("DATE_MATCHED"=TO_DATE('4712-12-31 00:00:00', 'yyyy-mm-dd
hh24:mi:ss'))

Note
-----
- 'PLAN_TABLE' is old version

19 rows selected.

Elapsed: 00:00:00.53

OK, my filter predicate is gone. But looking at the tkprof, I still find:

select count(*)
from
t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy')


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.28 0.27 0 241 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.28 0.27 0 241 0 1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 5

Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=241 pr=0 pw=0 time=277577 us)
90000 INDEX RANGE SCAN T1_DM (cr=241 pr=0 pw=0 time=270112 us)(object id 649118)


Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 0.00 0.00
**************************************************************************
select count(*)
from
t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy')


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.05 0.05 0 241 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.05 0.05 0 241 0 1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 5

Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=241 pr=0 pw=0 time=51866 us)
90000 INDEX RANGE SCAN T2_DM (cr=241 pr=0 pw=0 time=120 us)(object id 649119)


Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 0.00 0.00

Now what's the problem? I'm retrieving the same number of blocks (from cache, I might add). Yet, my elapsed time to retrieve data on the table with a constraint (even with the predicate constraint checking supposedly off) is .27 seconds vs. .05 for the table without the check constraint. To add insult to injury, if we pull out our old friend the Rule Based Optimizer:

select /*+ rule */ count(*)
from
t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy')


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.06 0.05 0 241 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 5 0.06 0.05 0 241 0 1

Misses in library cache during parse: 0
Optimizer mode: RULE
Parsing user id: 5

Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=241 pr=0 pw=0 time=53206 us)
90000 INDEX RANGE SCAN T1_DM (cr=241 pr=0 pw=0 time=86 us)(object id 649118)


Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 0.00 0.00

Ouch.

An omnipotent inside Oracle brings up a good point. It's the fetch where all the time is being spent. True, but Why? Why would the access path for the same plan be different? Still chugging along, looking for answers.

I'd be interested in your findings. I've tried this on Solaris 32, Solaris 64, Linux x86, and Linux x86_64. All similar (except x86_64 rocks and it's hard to tell a difference). I actually think the slower the box, the better.

script to reproduce:

set timing on
set echo on;
drop table t1;
create table t1 (
id number primary key,
date_matched date,
other_stuff varchar2(222),
constraint ck1 check (date_matched = trunc(date_matched))
);
drop table t2;
create table t2 (
id number primary key,
date_matched date,
other_stuff varchar2(222)
);
declare
dm date;
dc integer := 0;
begin
for i in 1..100000 loop
if mod(i,10) = 0 then
dm := trunc(sysdate + mod(dc,66));
dc := dc+1;
else
dm := to_date('12/31/4712','mm/dd/yyyy');
end if;
insert into t1 values (i, dm, rpad('x',mod(i,222)));
insert into t2 values (i, dm, rpad('x',mod(i,222)));
end loop;
commit;
end;
/
create index t1_dm on t1(date_matched);
create index t2_dm on t2(date_matched);
exec dbms_stats.gather_table_stats(ownname=>USER,tabname=>'T1',cascade=>true,estimate_percent=>NULL);
exec dbms_stats.gather_table_stats(ownname=>USER,tabname=>'T2',cascade=>true,estimate_percent=>NULL);
select * from v$version;
select date_matched, count(*) from t1 group by date_matched order by date_matched;
select date_matched, count(*) from t2 group by date_matched order by date_matched;
-- heres the explain plan
explain plan for select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);
explain plan for select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);
-- here's the explain plan
explain plan for select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);
explain plan for select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);
-- lets get some blocks in cache
select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
-- lets time one with tkprof
alter session set events '10046 trace name context forever, level 12';
alter session set tracefile_identifier = 't1t2_10046';
select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
-- yet RBO yields basically same result as t2
select /*+ rule */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
-- lets get a plan with the event turned on
alter session set events '10195 trace name context forever, level 1';
alter session set events '10046 trace name context forever, level 12';
explain plan for select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);
explain plan for select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select * from table(dbms_xplan.display);

-- lets time one with tkprof
alter session set tracefile_identifier = 't1t2_10195';
select count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
select count(*) from t2 where date_matched = to_date('12/31/4712','mm/dd/yyyy');
-- yet RBO yields basically same result as t2
select /*+ rule */ count(*) from t1 where date_matched = to_date('12/31/4712','mm/dd/yyyy');

Friday, January 05, 2007

Working with InnoDB Tablespaces


Is it me, or is working with InnoDB tablespaces akin to working with Oracle 6.0?


For example, today somebody filled up a filesystem by unintentially loading a large amount of data. It was development, so this stuff happens. Since it was development, I setup the InnoDB tablespace to start with size 10M and autoextend to whatever free space was available. The one datafile kept autoextending until it completely filled the disk. The developer dropped the table and thought that would free up the space.


I knew that wouldn't be the case, so I had to dump all the data, recreate the tablespace, and reload all my data. Pretty standard DBA stuff so far.


"This time", I thought to myself, " I'm going to create a couple files each 10m and let them autoextend to 10240m so this doesn't happen again".


Speedbump #1: InnoDB doesn't let you autoextend more than one file.


OK, I know my data is about 30G and we'll be doing some development, so I'll create three 10240m files and let the last one autoextend to 10240m. After 20 minutes of combing through the manuals trying to find a "DROP TABLESPACE" or similar command, I finally deduce that you can't drop a tablespace while the server is up.


Speedbump #2: The server (or instance for you Oracle people) has to be down to remove the tablespace.


So I shutdown the server, remove my datafiles per the docs, setup my config file, and restarted the server. The logfile spits out that it's pre-creating the files (as expected) but then throws an error message:



Error: All logfiles must be created at the same time.

Speedbump #3: You have to recreate the logfiles when you recreate the tablespace.


I don't want to recreate 30G of space, so I shutdown my server, remove the logfiles, and restart the server. Except this time I get another error:



InnoDB: Cannot initialize created log files because
InnoDB: data files are corrupt, or new data files were
InnoDB: created when the database was started previous
InnoDB: time but the database was not shutdown
InnoDB: normally after that.

Speedbump #4: You have to recreate your logfiles and datafiles at the same time.


It's not out of the realm of possibility that I'm doing something totally wrong or I don't understand InnoDB very well. Maybe my version (5.0.27) doesn't support these features but they are in a newer version. Or maybe it's just a hassle. I'd be interested in other's practical experiences with managing the InnoDB tablespace.


Powered by Zoundry

Thursday, January 04, 2007

Questions, Questions

Well it’s that time of year again! Companies’ budgets are set which means they’ll be looking to spend money, which means software purchases and upgrades, which means there will be a flurry of questions on the DBA forums on how to do things (and it’s already started).

I don’t know if this is going to turn into something of a vent for me but if anyone else feels the same or can give some insight that would lessen my frustrations please speak up.

Let me start off by saying that being a DBA in my eyes means that you have a great responsibility, one that should not be taken lightly. The company you work for depends on you for basically two things, ensure that their data is accessible and kept safe. If those two things are not met, the company is loosing money and potentially could bankrupt them if it’s not. Agreed? Yes, we are also responsible for daily flogging of developers but I look at that as a fringe benefit not a duty.

Hanging out on the DBA forums keeps me in tune with what’s going on in the Oracle world and also keeps me on my toes. However, *drum roll* when people start asking questions that you know that they didn’t do any type of research and simply posted the question really boils my potatoes. I mean the kind of question if you were to plug it into Google it would give you the answer right off the bat. When I see these things, I ask myself “why on earth would a company entrust their database to this individual?” and “what gives them the right to be called a DBA because a true DBA would of done research”. I honestly don’t know how Tom copes with it because I know he gets pelted with these things (Tom if you’re reading this please for the love of God tell me how you avoid these questions getting to you). I guess I feel like we as DBA’s are a whole and when one of us displays a lack of motivation makes us all look bad. Ok, I’m done.

*************
Last week an anonymous reader posted a question about Oracle Spatial and ArcSDE in one of my previous blogs. He asked if he has Oracle Spatial why would he need ArcSDE? The short answer….which would you rather do, load a large size raster image via the SDO_GEOR.importFrom package or use ArcCatalog? If you have your dbtune.sde file setup right it’s too easy :)
Here’s some light reading GeoRaster and Oracle Spatial.

Wednesday, January 03, 2007

Does everybody know this?

I've only been using my Palm Tungsten C for about 18 months. In that time, I only connected it to my desktop when I needed to update software or move some documents to the Palm. Never did a hot-sync since I thought I thought the data would always be on the Palm.

Did you know that when your Palm completely drains the power, it loses everything? Yup, everything. I know, backups, backups, backups....