Home » RDBMS Server » Performance Tuning » snapshot skipped in between the scheduled time (AWR) (11g, 11.2.0.1, window server 2008)
| snapshot skipped in between the scheduled time (AWR) [message #595514] |
Wed, 11 September 2013 08:11  |
ishika_20
Messages: 339
Registered: December 2006
Location: delhi
|
Senior Member |
|
|
Dear All,
Yesterday, there were performance issue at server. So today, when i am generating report for that particular period, found snapshot id sequence is serially but with skipped hourly timed. Instead of generating report at 15:30, it generated at 16:30.
Enter value for num_days: 2
Listing the last 2 days of Completed Snapshots
Snap
Instance DB Name Snap Id Snap Started Level
------------ ------------ --------- ------------------ -----
tagidev TAGIDEV 2857 10 Sep 2013 00:30 1
2858 10 Sep 2013 01:30 1
2859 10 Sep 2013 02:30 1
2860 10 Sep 2013 03:30 1
2861 10 Sep 2013 04:30 1
2862 10 Sep 2013 05:31 1
2863 10 Sep 2013 06:30 1
2864 10 Sep 2013 07:30 1
2865 10 Sep 2013 08:30 1
2866 10 Sep 2013 09:30 1
2867 10 Sep 2013 10:30 1
2868 10 Sep 2013 11:30 1
2869 10 Sep 2013 12:30 1
2870 10 Sep 2013 13:30 1
2871 10 Sep 2013 14:30 1
2872 10 Sep 2013 16:32 1
2873 10 Sep 2013 17:30 1
2874 10 Sep 2013 18:30 1
2875 10 Sep 2013 19:30 1
2876 10 Sep 2013 20:30 1
2877 10 Sep 2013 21:30 1
2878 11 Sep 2013 10:09 1
2879 11 Sep 2013 11:30 1
2880 11 Sep 2013 12:30 1
2881 11 Sep 2013 13:30 1
2882 11 Sep 2013 14:30 1
2883 11 Sep 2013 15:30 1
Below are the details at alert log -
Tue Sep 10 14:28:20 2013
Thread 1 cannot allocate new log, sequence 7029
Checkpoint not complete
Current log# 2 seq# 7028 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO02.LOG
Thread 1 advanced to log sequence 7029 (LGWR switch)
Current log# 3 seq# 7029 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO03.LOG
Tue Sep 10 14:28:54 2013
Immediate Kill Session#: 451, Serial#: 1870
Immediate Kill Session: sess: 000007FFC4652730 OS pid: 10784
Immediate Kill Session#: 486, Serial#: 470
Immediate Kill Session: sess: 000007FFC45ECDE0 OS pid: 12592
Immediate Kill Session#: 502, Serial#: 246
Immediate Kill Session: sess: 000007FFC45BE6E0 OS pid: 5136
Immediate Kill Session#: 456, Serial#: 338
Immediate Kill Session: sess: 000007FFC4643F00 OS pid: 5608
Immediate Kill Session#: 119, Serial#: 251
Immediate Kill Session: sess: 000007FFC41556B0 OS pid: 4216
Immediate Kill Session#: 42, Serial#: 2765
Immediate Kill Session: sess: 000007FFC4234E60 OS pid: 6488
Immediate Kill Session#: 473, Serial#: 356
Immediate Kill Session: sess: 000007FFC4612990 OS pid: 11908
Immediate Kill Session#: 29, Serial#: 1341
Immediate Kill Session: sess: 000007FFC425AA10 OS pid: 4868
Immediate Kill Session#: 460, Serial#: 1021
Immediate Kill Session: sess: 000007FFC4638540 OS pid: 12184
Tue Sep 10 14:29:08 2013
Thread 1 cannot allocate new log, sequence 7030
Checkpoint not complete
Current log# 3 seq# 7029 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO03.LOG
Thread 1 advanced to log sequence 7030 (LGWR switch)
Current log# 1 seq# 7030 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO01.LOG
Tue Sep 10 14:29:35 2013
Thread 1 cannot allocate new log, sequence 7031
Checkpoint not complete
Current log# 1 seq# 7030 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO01.LOG
Thread 1 advanced to log sequence 7031 (LGWR switch)
Current log# 2 seq# 7031 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO02.LOG
Tue Sep 10 14:30:25 2013
Thread 1 cannot allocate new log, sequence 7032
Checkpoint not complete
Current log# 2 seq# 7031 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO02.LOG
Thread 1 advanced to log sequence 7032 (LGWR switch)
Current log# 3 seq# 7032 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO03.LOG
Tue Sep 10 14:31:02 2013
kewastUnPackStats(): bad magic 1 (0x0000000039099665, 0)
kewastUnPackStats(): bad magic 1 (0x0000000039099665, 0)
kewastUnPackStats(): bad magic 1 (0x000000003909966D, 0)
kewastUnPackStats(): bad magic 1 (0x000000003909966D, 0)
kewastUnPackStats(): bad magic 1 (0x000000003909966D, 0)
kewastUnPackStats(): bad magic 1 (0x000000003909966D, 0)
kewastUnPackStats(): bad magic 1 (0x0000000039099665, 0)
kewastUnPackStats(): bad magic 1 (0x0000000039099665, 0)
Tue Sep 10 14:42:32 2013
Thread 1 advanced to log sequence 7033 (LGWR switch)
Current log# 1 seq# 7033 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO01.LOG
Tue Sep 10 15:19:22 2013
opidcl aborting process unknown ospid (3644) as a result of ORA-28
Tue Sep 10 15:19:22 2013
opidcl aborting process unknown ospid (1924) as a result of ORA-28
Tue Sep 10 16:17:20 2013
kewastUnPackStats(): bad magic 1 (0x000000001B3CF7DD, 0)
....
....
kewastUnPackStats(): bad magic 1 (0x000000001B3CE475, 0)
Tue Sep 10 15:19:22 2013
opidcl aborting process unknown ospid (6616) as a result of ORA-28
Tue Sep 10 15:19:22 2013
opidcl aborting process unknown ospid (2540) as a result of ORA-28
Tue Sep 10 15:26:21 2013
***********************************************************************
Tue Sep 10 15:13:18 2013
***********************************************************************
Tue Sep 10 15:37:33 2013
kewastUnPackStats(): bad magic 1 (0x000000001A8C5955, 0)
Tue Sep 10 15:19:22 2013
opidcl aborting process unknown ospid (14188) as a result of ORA-28
Tue Sep 10 15:19:22 2013
opidcl aborting process unknown ospid (7224) as a result of ORA-28
Tue Sep 10 15:33:48 2013
opidcl aborting process unknown ospid (12008) as a result of ORA-28
Tue Sep 10 15:42:24 2013
opidcl aborting process unknown ospid (2292) as a result of ORA-28
Tue Sep 10 15:42:24 2013
opidcl aborting process unknown ospid (6228) as a result of ORA-28
Tue Sep 10 16:08:19 2013
Process 0x000007FFC6B6D220 appears to be hung while dumping
Current time = 211426557, process death time = 211365920 interval = 60000
Attempting to kill process 0x000007FFC6B6D220 with OS pid = 11212
Tue Sep 10 16:17:26 2013
AUD: OS Error = 1717 encountered while writing audit record
opidcl aborting process unknown ospid (7196) as a result of ORA-28056
Tue Sep 10 16:17:26 2013
Errors in file e:\app\oracle\diag\rdbms\tagidev\tagidev\trace\tagidev_cjq0_12588.trc:
ORA-27300: OS system dependent operation:SuspendThread failed with status: 5
ORA-27301: OS failure message: Access is denied.
ORA-27302: failure occurred at: sssxcpttcs6
Tue Sep 10 16:17:26 2013
Errors in file e:\app\oracle\diag\rdbms\tagidev\tagidev\trace\tagidev_ora_13308.trc:
OSD-04503: Message 4503 not found; No message file for product=RDBMS, facility=SOSD
Image consistency checking encountered an error, checking disabled
Tue Sep 10 16:17:26 2013
Errors in file e:\app\oracle\diag\rdbms\tagidev\tagidev\trace\tagidev_ora_4984.trc:
OSD-04503: Message 4503 not found; No message file for product=RDBMS, facility=SOSD
Image consistency checking encountered an error, checking disabled
Tue Sep 10 16:17:26 2013
Errors in file e:\app\oracle\diag\rdbms\tagidev\tagidev\trace\tagidev_ora_11064.trc:
OSD-04503: Message 4503 not found; No message file for product=RDBMS, facility=SOSD
Image consistency checking encountered an error, checking disabled
Tue Sep 10 16:17:26 2013
Errors in file e:\app\oracle\diag\rdbms\tagidev\tagidev\trace\tagidev_ora_5096.trc:
OSD-04503: Message 4503 not found; No message file for product=RDBMS, facility=SOSD
Image consistency checking encountered an error, checking disabled
Tue Sep 10 16:17:26 2013
Errors in file e:\app\oracle\diag\rdbms\tagidev\tagidev\trace\tagidev_ora_10600.trc:
OSD-04503: Message 4503 not found; No message file for product=RDBMS, facility=SOSD
Image consistency checking encountered an error, checking disabled
Tue Sep 10 16:17:26 2013
Errors in file e:\app\oracle\diag\rdbms\tagidev\tagidev\trace\tagidev_ora_13560.trc:
OSD-04503: Message 4503 not found; No message file for product=RDBMS, facility=SOSD
Image consistency checking encountered an error, checking disabled
Tue Sep 10 16:17:26 2013
Errors in file e:\app\oracle\diag\rdbms\tagidev\tagidev\trace\tagidev_ora_1124.trc:
OSD-04503: Message 4503 not found; No message file for product=RDBMS, facility=SOSD
Image consistency checking encountered an error, checking disabled
kewastUnPackStats(): bad magic 1 (0x000000001A8C5955, 0)
Tue Sep 10 16:21:17 2013
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 3
Using LOG_ARCHIVE_DEST_1 parameter default value as E:\app\oracle\product\11.2.0\db_1\RDBMS
Autotune of undo retention is turned on.
IMODE=BR
ILAT =84
Tue Sep 10 16:21:29 2013
LICENSE_MAX_USERS = 0
SYS auditing is disabled
Starting up:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options.
Using parameter settings in server-side spfile E:\APP\ORACLE\PRODUCT\11.2.0\DB_1\DATABASE\SPFILETAGIDEV.ORA
System parameters with non-default values:
processes = 500
sessions = 772
nls_date_format = "dd/MM/yyyy"
memory_target = 3216M
control_files = "E:\APP\ORACLE\ORADATA\TAGIDEV\CONTROL01.CTL"
control_files = "E:\APP\ORACLE\ORADATA\TAGIDEV\CONTROL02.CTL"
db_block_size = 8192
compatible = "11.2.0.0.0"
undo_tablespace = "UNDOTBS1"
remote_login_passwordfile= "EXCLUSIVE"
db_domain = ""
dispatchers = "(PROTOCOL=TCP) (SERVICE=TAGIDEVXDB)"
local_listener = "(ADDRESS = (PROTOCOL = TCP)(HOST =192.168.30.26)(PORT = 1521))"
cursor_sharing = "similar"
audit_file_dest = "E:\APP\ORACLE\ADMIN\TAGIDEV\ADUMP"
audit_trail = "DB"
db_name = "TAGIDEV"
open_cursors = 6000
diagnostic_dest = "E:\APP\ORACLE"
Tue Sep 10 16:21:35 2013
PMON started with pid=2, OS id=3192
Tue Sep 10 16:21:35 2013
VKTM started with pid=3, OS id=3196 at elevated priority
VKTM running at (10)millisec precision with DBRM quantum (100)ms
Tue Sep 10 16:21:35 2013
GEN0 started with pid=4, OS id=3200
Tue Sep 10 16:21:36 2013
DIAG started with pid=5, OS id=3204
Tue Sep 10 16:21:36 2013
DBRM started with pid=6, OS id=3208
Tue Sep 10 16:21:36 2013
PSP0 started with pid=7, OS id=3212
Tue Sep 10 16:21:36 2013
DIA0 started with pid=8, OS id=3216
Tue Sep 10 16:21:36 2013
MMAN started with pid=9, OS id=3220
Tue Sep 10 16:21:36 2013
DBW0 started with pid=10, OS id=3224
Tue Sep 10 16:21:36 2013
LGWR started with pid=11, OS id=3228
Tue Sep 10 16:21:36 2013
CKPT started with pid=12, OS id=3232
Tue Sep 10 16:21:36 2013
SMON started with pid=13, OS id=3236
Tue Sep 10 16:21:36 2013
RECO started with pid=14, OS id=3240
Tue Sep 10 16:21:36 2013
MMON started with pid=15, OS id=3244
starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
starting up 1 shared server(s) ...
ORACLE_BASE from environment = E:\app\oracle
Tue Sep 10 16:21:36 2013
MMNL started with pid=16, OS id=3248
Tue Sep 10 16:21:42 2013
alter database mount exclusive
Tue Sep 10 16:21:49 2013
Successful mount of redo thread 1, with mount id 2075178134
Database mounted in Exclusive Mode
Lost write protection disabled
Tue Sep 10 16:21:52 2013
Completed: alter database mount exclusive
alter database open
Beginning crash recovery of 1 threads
parallel recovery started with 2 processes
Started redo scan
Completed redo scan
read 7 KB redo, 14 data blocks need recovery
Started redo application at
Thread 1: logseq 7033, block 31923
Recovery of Online Redo Log: Thread 1 Group 1 Seq 7033 Reading mem 0
Mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO01.LOG
Completed redo application of 0.00MB
Completed crash recovery at
Thread 1: logseq 7033, block 31937, scn 8261833345070
14 data blocks read, 14 data blocks written, 7 redo k-bytes read
Tue Sep 10 16:22:02 2013
Thread 1 advanced to log sequence 7034 (thread open)
Thread 1 opened at log sequence 7034
Current log# 2 seq# 7034 mem# 0: E:\APP\ORACLE\ORADATA\TAGIDEV\REDO02.LOG
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Tue Sep 10 16:22:02 2013
SMON: enabling cache recovery
Tue Sep 10 16:22:11 2013
Successfully onlined Undo Tablespace 2.
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is WE8MSWIN1252
No Resource Manager plan active
replication_dependency_tracking turned off (no async multimaster replication found)
Tue Sep 10 16:22:23 2013
Starting background process QMNC
Tue Sep 10 16:22:23 2013
QMNC started with pid=22, OS id=3092
Tue Sep 10 16:22:34 2013
Completed: alter database open
Tue Sep 10 16:22:47 2013
Starting background process CJQ0
Tue Sep 10 16:22:47 2013
CJQ0 started with pid=19, OS id=528
Tue Sep 10 16:29:44 2013
Starting background process SMCO
Tue Sep 10 16:29:45 2013
SMCO started with pid=50, OS id=4484
Tue Sep 10 16:42:41 2013
Here, i have 2 doubts -
1) why snap didn't started at 15:30?
2) since database just started at the scheduled time of AWR snap time. But generated at 16:32 instead of 16:30, though last services "SMCO" is started at 16:42. How it snap id generated for this particular time?
3) what does "kewastUnPackStats(): bad magic 1 (0x000000001B3CE48D, 0)" mean?
Regards,
Ishika
[Updated on: Wed, 11 September 2013 08:17] by Moderator Report message to a moderator |
|
|
|
|
|
|
|
| Re: snapshot skipped in between the scheduled time (AWR) [message #595518 is a reply to message #595514] |
Wed, 11 September 2013 08:30  |
John Watson
Messages: 8963
Registered: January 2010
Location: Global Village
|
Senior Member |
|
|
Your database is in a very sad state, and rather than trying to fix individual problems I would make some general changes:
Replace your online logfile groups with new groups that are twenty times as big. So if they are currently 50M, replace them with 1G groups.
Truncate your sus.aud$ table. It probably has millions of rows that you never look at.
Adjust cursor_sharing from similar to force. Similar is known to cause problems, you should rely on adaptive cursor sharing instead.
Apply the 11.2.0.3 patchset, 11.2.0.1 is known to have many issues.
Now run your application for a while. I promise you it will run faster and more reliably.
--
update: and, I forgot: delete everything from your Windows event logs.
[Updated on: Wed, 11 September 2013 08:31] Report message to a moderator |
|
|
|
|
|
| Re: snapshot skipped in between the scheduled time (AWR) [message #595563 is a reply to message #595518] |
Wed, 11 September 2013 14:26 |
Lalit Kumar B
Messages: 3174
Registered: May 2013
Location: World Wide on the Web
|
Senior Member |
|
|
Quote:Adjust cursor_sharing from similar to force. Similar is known to cause problems, you should rely on adaptive cursor sharing instead.
When I read this, the first thing that struck my mind is the T.Kyte's presentation on CURSOR_SHARING. I then experimented in my local environment, and finally got convinced on what he explained(with a set of extremely skewed data and varying literals in the column). I can't explain as beautifully as he did, so here is it
|
|
|
|
|
|
| Re: snapshot skipped in between the scheduled time (AWR) [message #595844 is a reply to message #595570] |
Sat, 14 September 2013 10:48 |
trantuananh24hg
Messages: 744
Registered: January 2007
Location: Ha Noi, Viet Nam
|
Senior Member |
|
|
M.Cadot, Mr! I agree with you!
In fact, we faced to the problem caused direct path from sql literal transforming by java without close cursor. Memory was lack, database not hang but no-more connection was signed up. When I changed the cursor_sharing from SIMILAR to FORCE, the cached buffer chained decreased. Of course, re-write SQL is the best performance tuning, but, indeed, decreasing the lack memory at this time was the good plan.
|
|
|
|
Goto Forum:
Current Time: Thu Jan 23 15:09:55 CST 2025
|
] 
Blog
Search
Help
Members
Register
Login
Home
