log location for shutdown of database

[Former Member]

Hi gurus,

My SAP is running on AIX OS and Oracle 10g database. today morning my database was abrubtly shut down on its own. one of my colleague who is also a basis consultant started the database manually. but i want to analyse what went wrong because of which the database was shutdown. where can i find logs which tells this. i tried reading log file alert_<SID>.log but it is a long file and hence its not opening properly. can u please tell how can i analyse this situation so that in future i can avoid this.

Regards,

Priya

[Former Member · Accepted solution]

Hi Priya,

u can check the alert_<SID>. log file using command "tail -500 alert_SID.log" which shows the last 500 lines of that file..

Also you can check the stopdb logfile which is located under "/home/SIDADM/stopdb.log".

- Bhupendra Patel

[Former Member · Accepted solution]

hi all,

my alert_<SID>. log file gives me this. but i am still not able to understand the exact cause of database shut down. My stopdb.log file shows me the log of an older date when the server was shutdown. Can you throw some light on it??

Thread 1 advanced to log sequence 22781

Current log# 4 seq# 22781 mem# 0: /oracle/IRP/origlogB/log_g14m1.dbf

Current log# 4 seq# 22781 mem# 1: /oracle/IRP/mirrlogB/log_g14m2.dbf

Wed Mar 3 22:09:38 2010

Completed checkpoint up to RBA [0x58fd.2.10], SCN: 339722427

Wed Mar 3 22:32:55 2010

d.43c7.0]

Wed Mar 3 23:02:56 2010

d.779c.0]

Wed Mar 3 23:32:57 2010

d.c12a.0]

Thu Mar 4 00:02:57 2010

d.109ec.0]

Thu Mar 4 00:30:58 2010

Beginning log switch checkpoint up to RBA [0x58fe.2.10], SCN: 339771396

Thread 1 advanced to log sequence 22782

Current log# 2 seq# 22782 mem# 0: /oracle/IRP/origlogB/log_g12m1.dbf

Current log# 2 seq# 22782 mem# 1: /oracle/IRP/mirrlogB/log_g12m2.dbf

Thu Mar 4 00:32:58 2010

fe.c6f.0]

Thu Mar 4 00:36:04 2010

Completed checkpoint up to RBA [0x58fe.2.10], SCN: 339771396

Thu Mar 4 01:02:59 2010

e.47da.0]

Thu Mar 4 01:33:00 2010

e.8380.0]

Thu Mar 4 02:00:06 2010

Shutting down instance: further logons disabled

Thu Mar 4 02:00:06 2010

Stopping background process QMNC

Thu Mar 4 02:00:06 2010

Stopping background process CJQ0

Thu Mar 4 02:00:09 2010

Stopping background process MMNL

Thu Mar 4 02:00:10 2010

Stopping background process MMON

Thu Mar 4 02:00:11 2010

Shutting down instance (immediate)

License high water mark = 39

Thu Mar 4 02:00:11 2010

Stopping Job queue slave processes

Thu Mar 4 02:00:11 2010

Job queue slave processes stopped

Thu Mar 4 02:00:16 2010

Process OS id : 717306 alive after kill

Errors in file

Thu Mar 4 02:02:11 2010

ALTER DATABASE CLOSE NORMAL

Thu Mar 4 02:02:12 2010

SMON: disabling tx recovery

SMON: disabling cache recovery

Thu Mar 4 02:02:12 2010

Shutting down archive processes

Archiving is disabled

Thu Mar 4 02:02:17 2010

ARCH shutting down

ARC1: Archival stopped

Thu Mar 4 02:02:22 2010

ARCH shutting down

ARC0: Archival stopped

Thu Mar 4 02:02:23 2010

Thread 1 closed at log sequence 22782

Successful close of redo thread 1

Thu Mar 4 02:02:23 2010

Completed: ALTER DATABASE CLOSE NORMAL

Thu Mar 4 02:02:23 2010

ALTER DATABASE DISMOUNT

Completed: ALTER DATABASE DISMOUNT

ARCH: Archival disabled due to shutdown: 1089

Shutting down archive processes

Archiving is disabled

Archive process shutdown avoided: 0 active

ARCH: Archival disabled due to shutdown: 1089

Shutting down archive processes

Archiving is disabled

Archive process shutdown avoided: 0 active

Thu Mar 4 02:02:48 2010

Starting ORACLE instance (normal)

Thu Mar 4 02:02:48 2010

Specified value of sga_max_size is too small, bumping to 4513071104

LICENSE_MAX_SESSION = 0

LICENSE_SESSIONS_WARNING = 0

Picked latch-free SCN scheme 3

Autotune of undo retention is turned on.

IMODE=BR

ILAT =10

LICENSE_MAX_USERS = 0

SYS auditing is disabled

ksdpec: called for event 13740 prior to event group initialization

Starting up ORACLE RDBMS Version: 10.2.0.2.0.

System parameters with non-default values:

processes = 80

sessions = 96

event = 10191 trace name context forever, level 1

sga_max_size = 4513071104

shared_pool_size = 2231369728

shared_pool_reserved_size= 222868537

filesystemio_options = setall

P/origlogB/cntrl/cntrlIRP.dbf, /oracle/IRP/sapdata1/cntrl/cntrlIRP.dbf

control_file_record_keep_time= 30

db_block_size = 8192

db_cache_size = 2231369728

compatible = 10.2.0

log_archive_dest = /oracle/IRP/oraarch/IRParch

log_buffer = 14251008

log_checkpoint_interval = 0

db_files = 254

log_checkpoints_to_alert = TRUE

dml_locks = 4000

undo_management = AUTO

undo_tablespace = PSAPUNDO

undo_retention = 43200

recyclebin = off

remote_os_authent = TRUE

remote_login_passwordfile= EXCLUSIVE

job_queue_processes = 1

background_dump_dest = /oracle/IRP/saptrace/background

user_dump_dest = /oracle/IRP/saptrace/usertrace

core_dump_dest = /oracle/IRP/saptrace/background

optimizer_features_enable= 10.2.0.1

sort_area_size = 2097152

sort_area_retained_size = 0

db_name = IRP

open_cursors = 800

optimpeek_user_binds = FALSE

pga_aggregate_target = 2971580497

workarea_size_policy = AUTO

statistics_level = typical

PMON started with pid=2, OS id=717142

PSP0 started with pid=3, OS id=475378

MMAN started with pid=4, OS id=708896

DBW0 started with pid=5, OS id=471246

LGWR started with pid=6, OS id=635372

CKPT started with pid=7, OS id=151706

SMON started with pid=8, OS id=188508

RECO started with pid=9, OS id=520374

CJQ0 started with pid=10, OS id=516138

MMON started with pid=11, OS id=631242

MMNL started with pid=12, OS id=495664

Thu Mar 4 02:02:48 2010

ALTER DATABASE MOUNT

Thu Mar 4 02:02:52 2010

Setting recovery target incarnation to 1

Thu Mar 4 02:02:52 2010

Successful mount of redo thread 1, with mount id 2397773896

Thu Mar 4 02:02:52 2010

Database mounted in Exclusive Mode

Completed: ALTER DATABASE MOUNT

Thu Mar 4 02:02:52 2010

ALTER DATABASE OPEN

Thu Mar 4 02:02:52 2010

Errors in file /oracle/IRP/saptrace/background/irp_dbw0_471246.trc:

ORA-01157: cannot identify/lock data file 2 - see DBWR trace file

ORA-01110: data file 2: '/oracle/IRP/sapdata3/undo_1/undo.data1'

ORA-27041: unable to open file

IBM AIX RISC System/6000 Error: 22: Invalid argument

Additional information: 2

ORA-1157 signalled during: ALTER DATABASE OPEN...

Thu Mar 4 08:51:08 2010

Adjusting the default value of parameter parallel_max_servers

from 160 to 65 due to the value of parameter processes (80)

Thu Mar 4 08:51:08 2010

Starting ORACLE instance (normal)

Adjusting the default value of parameter parallel_max_servers

from 160 to 65 due to the value of parameter processes (80)

Thu Mar 4 08:52:30 2010

Starting ORACLE instance (normal)

Thu Mar 4 08:54:19 2010

Shutting down instance: further logons disabled

Thu Mar 4 08:54:19 2010

Stopping background process CJQ0

Thu Mar 4 08:54:19 2010

Stopping background process MMNL

Thu Mar 4 08:54:20 2010

Stopping background process MMON

Thu Mar 4 08:54:21 2010

Shutting down instance (normal)

License high water mark = 4

Thu Mar 4 08:54:21 2010

Stopping Job queue slave processes

Thu Mar 4 08:54:21 2010

Job queue slave processes stopped

Thu Mar 4 08:54:21 2010

ALTER DATABASE CLOSE NORMAL

ORA-1109 signalled during: ALTER DATABASE CLOSE NORMAL...

Thu Mar 4 08:54:21 2010

ALTER DATABASE DISMOUNT

Completed: ALTER DATABASE DISMOUNT

ARCH: Archival disabled due to shutdown: 1090

Shutting down archive processes

Archiving is disabled

Archive process shutdown avoided: 0 active

ARCH: Archival disabled due to shutdown: 1090

Shutting down archive processes

Archiving is disabled

Archive process shutdown avoided: 0 active

Thu Mar 4 08:54:32 2010

Starting ORACLE instance (normal)

Thu Mar 4 08:54:32 2010

Specified value of sga_max_size is too small, bumping to 4513071104

LICENSE_MAX_SESSION = 0

LICENSE_SESSIONS_WARNING = 0

Picked latch-free SCN scheme 3

Autotune of undo retention is turned on.

IMODE=BR

ILAT =10

LICENSE_MAX_USERS = 0

SYS auditing is disabled

ksdpec: called for event 13740 prior to event group initialization

Starting up ORACLE RDBMS Version: 10.2.0.2.0.

System parameters with non-default values:

processes = 80

sessions = 96

event = 10191 trace name context forever, level 1

sga_max_size = 4513071104

shared_pool_size = 2231369728

shared_pool_reserved_size= 222868537

filesystemio_options = setall

P/origlogB/cntrl/cntrlIRP.dbf, /oracle/IRP/sapdata1/cntrl/cntrlIRP.dbf

control_file_record_keep_time= 30

db_block_size = 8192

db_cache_size = 2231369728

compatible = 10.2.0

log_archive_dest = /oracle/IRP/oraarch/IRParch

log_buffer = 14251008

log_checkpoint_interval = 0

db_files = 254

log_checkpoints_to_alert = TRUE

dml_locks = 4000

undo_management = AUTO

undo_tablespace = PSAPUNDO

undo_retention = 43200

recyclebin = off

remote_os_authent = TRUE

remote_login_passwordfile= EXCLUSIVE

job_queue_processes = 1

background_dump_dest = /oracle/IRP/saptrace/background

user_dump_dest = /oracle/IRP/saptrace/usertrace

core_dump_dest = /oracle/IRP/saptrace/background

optimizer_features_enable= 10.2.0.1

sort_area_size = 2097152

sort_area_retained_size = 0

db_name = IRP

open_cursors = 800

optimpeek_user_binds = FALSE

pga_aggregate_target = 2971580497

workarea_size_policy = AUTO

statistics_level = typical

PMON started with pid=2, OS id=631246

PSP0 started with pid=3, OS id=516160

MMAN started with pid=4, OS id=471250

DBW0 started with pid=5, OS id=553404

LGWR started with pid=6, OS id=545076

CKPT started with pid=9, OS id=627090

SMON started with pid=8, OS id=623056

RECO started with pid=7, OS id=426188

CJQ0 started with pid=10, OS id=377036

MMON started with pid=11, OS id=618858

MMNL started with pid=12, OS id=565430

Thu Mar 4 08:54:32 2010

ALTER DATABASE MOUNT

Thu Mar 4 08:54:36 2010

Setting recovery target incarnation to 1

Thu Mar 4 08:54:36 2010

Successful mount of redo thread 1, with mount id 2397797576

Thu Mar 4 08:54:36 2010

Database mounted in Exclusive Mode

Completed: ALTER DATABASE MOUNT

Thu Mar 4 08:54:36 2010

ALTER DATABASE OPEN

Thu Mar 4 08:54:43 2010

LGWR: STARTING ARCH PROCESSES

ARC0 started with pid=14, OS id=475148

Thu Mar 4 08:54:44 2010

ARC0: Archival started

ARC1: Archival started

LGWR: STARTING ARCH PROCESSES COMPLETE

ARC1 started with pid=15, OS id=708912

Thu Mar 4 08:54:44 2010

Thread 1 opened at log sequence 22782

Current log# 2 seq# 22782 mem# 0: /oracle/IRP/origlogB/log_g12m1.dbf

Current log# 2 seq# 22782 mem# 1: /oracle/IRP/mirrlogB/log_g12m2.dbf

Successful open of redo thread 1

Thu Mar 4 08:54:44 2010

MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set

Thu Mar 4 08:54:44 2010

ARC0: STARTING ARCH PROCESSES

Thu Mar 4 08:54:44 2010

ARC1: Becoming the 'no FAL' ARCH

ARC1: Becoming the 'no SRL' ARCH

Thu Mar 4 08:54:44 2010

SMON: enabling cache recovery

Thu Mar 4 08:54:44 2010

ARC2: Archival started

ARC0: STARTING ARCH PROCESSES COMPLETE

ARC0: Becoming the heartbeat ARCH

ARC2 started with pid=16, OS id=684468

Thu Mar 4 08:54:44 2010

fe.10309.0]

Thu Mar 4 08:54:44 2010

Successfully onlined Undo Tablespace 1.

Thu Mar 4 08:54:44 2010

SMON: enabling tx recovery

Thu Mar 4 08:54:44 2010

Database Characterset is UTF8

nd)

Starting background process QMNC

QMNC started with pid=18, OS id=717190

Thu Mar 4 08:54:46 2010

Completed: ALTER DATABASE OPEN

Thu Mar 4 08:55:40 2010

Beginning log switch checkpoint up to RBA [0x58ff.2.10], SCN: 339802840

Thread 1 advanced to log sequence 22783

Current log# 3 seq# 22783 mem# 0: /oracle/IRP/origlogA/log_g13m1.dbf

Current log# 3 seq# 22783 mem# 1: /oracle/IRP/mirrlogA/log_g13m2.dbf

Thu Mar 4 08:55:40 2010

Shutting down archive processes

Thu Mar 4 08:55:43 2010

Shutting down archive processes

Archive process shutdown avoided: 2 active

Thu Mar 4 08:55:46 2010

ARCH shutting down

ARC2: Archival stopped

Thu Mar 4 09:00:45 2010

Completed checkpoint up to RBA [0x58ff.2.10], SCN: 339802840

Thu Mar 4 09:24:49 2010

f.d8fa.0]

Thu Mar 4 09:33:10 2010

IRP.dbf'

Thu Mar 4 09:33:11 2010

ackup/cntrlIRP.dbf'

Thu Mar 4 09:54:49 2010

ff.12015.0]

Thu Mar 4 10:01:25 2010

Beginning log switch checkpoint up to RBA [0x5900.2.10], SCN: 339839728

Thread 1 advanced to log sequence 22784

Current log# 1 seq# 22784 mem# 0: /oracle/IRP/origlogA/log_g11m1.dbf

Current log# 1 seq# 22784 mem# 1: /oracle/IRP/mirrlogA/log_g11m2.dbf

Thu Mar 4 10:06:30 2010

Completed checkpoint up to RBA [0x5900.2.10], SCN: 339839728

Thu Mar 4 10:24:50 2010

0.4f53.0]

Thu Mar 4 10:38:03 2010

Beginning log switch checkpoint up to RBA [0x5901.2.10], SCN: 339860100

Thread 1 advanced to log sequence 22785

Current log# 4 seq# 22785 mem# 0: /oracle/IRP/origlogB/log_g14m1.dbf

Current log# 4 seq# 22785 mem# 1: /oracle/IRP/mirrlogB/log_g14m2.dbf

[Former Member · Accepted solution]

It seems the database did not abrubtly shut down on its own.

Someone or some program did it, at Thu Mar 4 02:00:06 2010.

You will have to find out what might be the reason.

Just a guess: Did someone schedule an offline backup at 2:00 AM ?

[Former Member · Accepted solution]

hi joe!

u were right even i was surprised how the databse has gone down as i couldnt decipher any thing much from alert_SID.log..

then checked the backup log and saw that actually someone had scheduled offline backup post which database didnt come up.

when i asked my colleagues he then said that he had done it which he had forgotten about

Thanks a lot!!

Regards,

Priya

[Former Member]

i tried reading log file alert_<SID>.log but it is a long file and hence its not opening properly

Alert log can tell you the exact reason behind the abnormal shutdown of database, just use below commands to find the exact reason....for openig the file at OS(*ix) level just go through below commands....

more

tail -f

vi (use vi command only if you are expert or having minimal knowledge on how to use)

Regards,

Nick Loy