During the weekend I’ve setup two virtual box standard edition 12c machines to test
Dbvisit Standby. During the setup I had some issues with archive log gap’s, while collecting information for Dbvisit’s excellent support I noticed that v$asm_diskgroup was empty …
However asmcmd returned information I couldn’t understand why and started digging ….
together with my twitter friends @drune and @OsamaOracle who made good suggestions …
SQL> select upper(name) NAME from v$asm_diskgroup;
no rows selected
SQL> select * from v$asm_diskgroup;
no rows selected
[oracle@SE1] asmcmd
ASMCMD> lsdg
State Type Rebal Sector Block AU Total_MB Free_MB Req_mir_free_MB Usable_file_MB Offline_disks Voting_files Name
MOUNTED EXTERN N 512 4096 1048576 4094 3694 0 3694 0 N ARCHDG1/
MOUNTED EXTERN N 512 4096 1048576 10228 7522 0 7522 0 N DATADG1/
At the same time that @martinberx was suggesting it, I started to use the 10046 trace to see what happens
when I execute
select * from v$asm_diskgroup;
=====================
PARSING IN CURSOR #139820964230440 len=29 dep=0 uid=0 oct=3 lid=0 tim=582985779 hv=3194982195 ad=’9f2f6808′ sqlid=’38z4yk2z6z3tm’
select * from v$asm_diskgroup
END OF STMT
PARSE #139820964230440:c=2000,e=6212,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3236948515,tim=582985778
EXEC #139820964230440:c=0,e=63,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3236948515,tim=582985923
WAIT #139820964230440: nam=’SQL*Net message to client’ ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=582985965
Initialized kgfd context:0x7f2a9ae77f00
Terminating kgfd context 0x7f2a9ae77f00
FETCH #139820964230440:c=3000,e=12273,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3236948515,tim=582998295
STAT #139820964230440 id=1 cnt=0 pid=0 pos=1 obj=0 op=’FIXED TABLE FULL X$KFGRP (cr=0 pr=0 pw=0 time=12271 us)’
*** 2014-02-10 22:05:10.377
WAIT #139820964230440: nam=’SQL*Net message from client’ ela= 18538852 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=601539107
CLOSE #139820964230440:c=0,e=10,dep=0,type=0,tim=601539195
and also the lsdg action in asmcmd
1* select sid,serial#,module from v$session
SID SERIAL# MODULE
29 7 perl@SE1 (TNS V1-V3)
select saddr,paddr from v$session where sid=29 and serial#=7;
SADDR PADDR
—————- —————-
00000000A3B64C78 00000000A397A378
SQL> select spid from v$process where addr=’00000000A397A378’;
SPID
————————
2818
SQL> oradebug setospid 2818;
Oracle pid: 23, Unix process pid: 2818, image: oracle@SE1 (TNS V1-V3)
SQL> ORADEBUG EVENT 10046 TRACE NAME CONTEXT FOREVER, LEVEL 8;
Statement processed.
SQL> oradebug tracefile_name;
/u01/app/oracle/diag/asm/+asm/+ASM/trace/+ASM_ora_2818.trc
which generates this :
Trace file /u01/app/oracle/diag/asm/+asm/+ASM/trace/+ASM_ora_2818.trc
Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 – 64bit Production
With the Automatic Storage Management option
ORACLE_HOME = /u01/app/oracle/product/12.1.0/grid
System name: Linux
Node name: SE1
Release: 3.8.13-16.3.1.el6uek.x86_64
Version: #2 SMP Tue Dec 17 11:24:44 PST 2013
Machine: x86_64
Instance name: +ASM
Redo thread mounted by this instance: 0
Oracle process number: 23
Unix process pid: 2818, image: oracle@SE1 (TNS V1-V3)
*** 2014-02-10 22:13:26.120
*** SESSION ID:(29.7) 2014-02-10 22:13:26.120
*** CLIENT ID:() 2014-02-10 22:13:26.120
*** SERVICE NAME:() 2014-02-10 22:13:26.120
*** MODULE NAME:(perl@SE1 (TNS V1-V3)) 2014-02-10 22:13:26.120
*** ACTION NAME:() 2014-02-10 22:13:26.120
Received ORADEBUG command (#1) ‘EVENT 10046 TRACE NAME CONTEXT FOREVER, LEVEL 8’ from process ‘2723’
*** 2014-02-10 22:13:26.121
Finished processing ORADEBUG command (#1) ‘EVENT 10046 TRACE NAME CONTEXT FOREVER, LEVEL 8’
*** 2014-02-10 22:13:40.668
Received ORADEBUG command (#2) ‘tracefile_name’ from process ‘2723’
*** 2014-02-10 22:13:40.669
Finished processing ORADEBUG command (#2) ‘tracefile_name’
*** 2014-02-10 22:15:24.837
WAIT #140181062274144: nam=’SQL*Net message from client’ ela= 558311444 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1215999416
CLOSE #140181062274144:c=0,e=10,dep=0,type=0,tim=1215999600
=====================
PARSING IN CURSOR #140181062274144 len=47 dep=0 uid=0 oct=3 lid=0 tim=1216001667 hv=2237657138 ad=’9f36be20′ sqlid=’acnhubu2pzw1k’
/* ASMCMD */ select * from v$asm_diskgroup_stat
END OF STMT
PARSE #140181062274144:c=1000,e=1997,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=486334127,tim=1216001665
WAIT #140181062274144: nam=’SQL*Net message to client’ ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216001773
WAIT #140181062274144: nam=’SQL*Net message from client’ ela= 1356 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216003177
EXEC #140181062274144:c=0,e=48,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=486334127,tim=1216003273
WAIT #140181062274144: nam=’Disk file operations I/O’ ela= 2237 FileOperation=2 fileno=0 filetype=15 obj#=-1 tim=1216006405
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 2558 group=2 obj=1 block=8 obj#=-1 tim=1216009066
WAIT #140181062274144: nam=’Disk file operations I/O’ ela= 20 FileOperation=2 fileno=0 filetype=15 obj#=-1 tim=1216009216
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 811 group=2 obj=8 block=0 obj#=-1 tim=1216010056
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 602 group=2 obj=8 block=60 obj#=-1 tim=1216010750
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 1059 group=2 obj=8 block=120 obj#=-1 tim=1216011895
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 658 group=2 obj=8 block=180 obj#=-1 tim=1216012648
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 674 group=2 obj=8 block=240 obj#=-1 tim=1216013413
WAIT #140181062274144: nam=’SQL*Net message to client’ ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216013620
WAIT #140181062274144: nam=’Disk file operations I/O’ ela= 20 FileOperation=2 fileno=0 filetype=15 obj#=-1 tim=1216013781
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 599 group=1 obj=8 block=60 obj#=-1 tim=1216014409
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 639 group=1 obj=8 block=120 obj#=-1 tim=1216015116
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 426 group=1 obj=8 block=180 obj#=-1 tim=1216015650
WAIT #140181062274144: nam=’ASM sync cache disk read’ ela= 882 group=1 obj=8 block=240 obj#=-1 tim=1216016620
FETCH #140181062274144:c=4000,e=13420,p=0,cr=0,cu=0,mis=0,r=2,dep=0,og=1,plh=486334127,tim=1216016721
STAT #140181062274144 id=1 cnt=2 pid=0 pos=1 obj=0 op=’FIXED TABLE FULL X$KFGRP_STAT (cr=0 pr=0 pw=0 time=13352 us)’
WAIT #140181062274144: nam=’SQL*Net message from client’ ela= 1327 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216018167
CLOSE #140181062274144:c=0,e=7,dep=0,type=0,tim=1216018228
=====================
PARSING IN CURSOR #140181062273064 len=1397 dep=2 uid=0 oct=3 lid=0 tim=1216021926 hv=2564988146 ad=’9f2c77d8′ sqlid=’1gskc7qcf577k’
select inst_id, number_kfgbrb, ‘REBAL’, decode(op_kfgbrb, 1, ‘RESYNC’, 2, ‘RESILVER’, 3, ‘REBALANCE’, ‘COMPACT’), decode(error_kfgbrb, 0, decode(sign(state_kfgbrb – op_kfgbrb), 0, decode((select state_kfgmg from x$kfgmg where number_kfgmg=number_kfgbrb and op_kfgmg=1 and pass_kfgmg=op_kfgbrb), 3, ‘REAP’, decode((select rebalst_kfgmg from x$kfgmg where number_kfgmg=number_kfgbrb and op_kfgmg = 1 and pass_kfgmg=op_kfgbrb), 1, ‘EST’, 3, ‘EST’, 5, ‘EST’, 0, ‘WAIT’, ”, ‘WAIT’, ‘RUN’)), 1, ‘DONE’, ‘WAIT’), ‘ERRS’), power_kfgbrb, (select actual_kfgmg from x$kfgmg where number_kfgmg=number_kfgbrb and op_kfgmg = 1 and pass_kfgmg=op_kfgbrb), (select sofar_kfgmg from x$kfgmg where number_kfgmg=number_kfgbrb and op_kfgmg = 1 and pass_kfgmg=op_kfgbrb), (select work_kfgmg from x$kfgmg where number_kfgmg=number_kfgbrb and op_kfgmg = 1 and pass_kfgmg=op_kfgbrb), (select rate_kfgmg from x$kfgmg where number_kfgmg=number_kfgbrb and op_kfgmg = 1 and pass_kfgmg=op_kfgbrb), (select time_kfgmg from x$kfgmg where number_kfgmg=number_kfgbrb and op_kfgmg = 1 and pass_kfgmg=op_kfgbrb), decode(error_kfgbrb, 0, ”, ‘ORA-‘ || error_kfgbrb), con_id from x$kfgbrb
END OF STMT
PARSE #140181062273064:c=2000,e=2870,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=4,plh=2802141400,tim=1216021925
CLOSE #140181062273064:c=0,e=7,dep=2,type=0,tim=1216022547
=====================
PARSING IN CURSOR #140181062274144 len=181 dep=1 uid=0 oct=3 lid=0 tim=1216024992 hv=2797184208 ad=’9f2ccb18′ sqlid=’fgj46y2mbm96h’
select group_number, operation, pass, state, power, actual, sofar, est_work, est_rate, est_minutes, error_code, con_id from gv$asm_operation where inst_id = USERENV(‘Instance’)
END OF STMT
PARSE #140181062274144:c=6000,e=6327,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=2802141400,tim=1216024982
CLOSE #140181062274144:c=0,e=7,dep=1,type=0,tim=1216025086
=====================
PARSING IN CURSOR #140181062275568 len=71 dep=0 uid=0 oct=3 lid=0 tim=1216025673 hv=2266270607 ad=’9f2d1998′ sqlid=’3k7n9vf3j92wg’
/* ASMCMD */ select operation from v$asm_operation where group_number=1
END OF STMT
PARSE #140181062275568:c=6000,e=7400,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=4014866482,tim=1216025672
WAIT #140181062275568: nam=’SQL*Net message to client’ ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216025742
WAIT #140181062275568: nam=’SQL*Net message from client’ ela= 268 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216026079
EXEC #140181062275568:c=0,e=30,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4014866482,tim=1216026145
FETCH #140181062275568:c=0,e=77,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4014866482,tim=1216026246
STAT #140181062275568 id=1 cnt=0 pid=0 pos=1 obj=0 op=’FIXED TABLE FIXED INDEX X$KFGBRB (ind:1) (cr=0 pr=0 pw=0 time=80 us)’
WAIT #140181062275568: nam=’SQL*Net message to client’ ela= 0 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216026276
WAIT #140181062275568: nam=’SQL*Net message from client’ ela= 316 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216026592
CLOSE #140181062275568:c=0,e=122,dep=0,type=0,tim=1216026747
=====================
PARSING IN CURSOR #140181062275568 len=71 dep=0 uid=0 oct=3 lid=0 tim=1216028147 hv=768609183 ad=’9f2c0e50′ sqlid=’4w32mxwqx02wz’
/* ASMCMD */ select operation from v$asm_operation where group_number=2
END OF STMT
PARSE #140181062275568:c=1000,e=1352,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=4014866482,tim=1216028146
WAIT #140181062275568: nam=’SQL*Net message to client’ ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216028221
WAIT #140181062275568: nam=’SQL*Net message from client’ ela= 222 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216028475
EXEC #140181062275568:c=0,e=21,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4014866482,tim=1216028530
FETCH #140181062275568:c=0,e=56,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4014866482,tim=1216028608
STAT #140181062275568 id=1 cnt=0 pid=0 pos=1 obj=0 op=’FIXED TABLE FIXED INDEX X$KFGBRB (ind:1) (cr=0 pr=0 pw=0 time=55 us)’
WAIT #140181062275568: nam=’SQL*Net message to client’ ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1216028685
*** 2014-02-10 22:15:48.367
Received ORADEBUG command (#3) ‘EVENT 10046 TRACE NAME CONTEXT OFF’ from process ‘2723’
*** 2014-02-10 22:15:48.370
Finished processing ORADEBUG command (#3) ‘EVENT 10046 TRACE NAME CONTEXT OFF’
Hmm strange it uses v$asm_diskgroup_stat and other views.
after checking disk permissions with kfod which looked fine
[oracle@SE1 redhat]$ kfod disks=all
——————————————————————————–
Disk Size Path User Group
================================================================================
1: 5114 Mb /dev/asm-disk1 oracle dba
2: 4094 Mb /dev/asm-disk2 oracle dba
3: 5114 Mb /dev/asm-disk3 oracle dba
4: 12288 Mb /dev/sda root dba
5: 2987 Mb /dev/sda3 root dba
6: 35840 Mb /dev/sdb root dba
7: 5120 Mb /dev/sdc root dba
8: 4096 Mb /dev/sdd root dba
9: 5120 Mb /dev/sde root dba
——————————————————————————–
ORACLE_SID ORACLE_HOME
================================================================================
+ASM /u01/app/oracle/product/12.1.0/grid
Martin Carsten Bach aka as @MartinDBA came with this suggestion :
 |
MartinDBA @pfierens @martinberx you could check permission on the block devices, kfod disks=all (might need to set ask_diskstring too) 10/02/14 22:46 |
And that seemed to do it, for some reason the asm_diskstring was not set … after setting the asm_diskstring select from v$asm_diskgroup worked again.
SQL> select name from v$asm_diskgroup;
NAME
——————————
DATADG1
ARCHDG1
Big Thanks to all who helped me here, twitter is great and having friend out there is even better, thank you guys !!!
BTW after fixing the v$asm_diskgroup dbvisit standby started resolving the archive log gap, it looks like a great product I will be investigating deeper ….
