ASM device error ORA-27041 ORA-15025 ORA-15081 (Doc ID 1487475.1)

Description Summary.
A large number of ORA-27041 ORA-15025 ORA-15081 errors were found in the database alert, first check the status of asm’s disk group, the status and permissions of the corresponding disk drive are all normal, check the alert log of asm did not see the refresh.
It looks like a problem with disk permissions, but if it is really a problem with disk permissions, then the database should hang, but when I look at the business sessions, they are all normal. At this point there is no clue, check mos, in fact, already have the answer, but did not understand the meaning of mos.
After insisting on the principle of 30 minutes of communication, communicate whether there are disk-related changes. According to the uid in trc, it was confirmed that it was related to the DSG user of the operating system, and there was no clear answer for consulting the business. Check the process under this user, found a large number of executed scripts, check the corresponding log, found that the time of program execution and the time of database error reporting match, and error reporting consistent. The final decision was that the program was prompted for insufficient permissions to access the disk because the dsg user lacked the appropriate permissions for the disk group.

The relevant information is as follows.
1.Environment：11.2.0.4
2.Symptoms:
1)error
Tue Sep ORA-2704128 11:08:13 2021
Errors in file /XXX/app/oracle/diag/rdbms/xxx/xxx1/trace/xxx1_ora_9178000.trc:
ORA-15025: could not open disk “/dev/rhdisk12”
ORA-27041: unable to open file
IBM AIX RISC System/6000 Error: 13: Permission denied
Additional information: 3
Additional information: 4
Additional information: 138444804
Errors in file /XXX/app/oracle/diag/rdbms/xxx/xxx1/trace/xxx1_ora_9178000.trc:
ORA-15025: could not open disk “/dev/rhdisk12″
ORA-27041: unable to open file
IBM AIX RISC System/6000 Error: 13: Permission denied
Additional information: 3
Additional information: 4
Additional information: 138444804
WARNING: failed to read mirror side 1 of virtual extent 0 logical extent 0 of file 3103 in group [1.374353710] from disk DATA_0002 allocation unit 893192 r
eason error; if possible, will try another mirror side
Errors in file /XXX/app/oracle/diag/rdbms/xxx/xxx1/trace/xxx1_ora_9178000.trc:
ORA-00202: control file: ‘+DATA/xxx/controlfile/current.257.1062864093.bak’
ORA-15081: failed to submit an I/O operation to a disk
Tue Sep 28 11:08:14 2021
2)Disk Related Queries
SQL> select DISK_NUMBER,B.NAME GROUP_NAME,a.name diskname,a.free_MB/1024 FREE_GB,a.TOTAL_MB/1024 TOTAL_GB,a.free_mb/a.total_mb*100 free_percentage ,a.path,A.STATE FROM V$ASM_DISK A,V$ASM_DISKGROUP B WHERE A.GROUP_NUMBER=B.GROUP_NUMBER order by b.name,DISK_NUMBER ;
DISK_NUMBER GROUP_NAME DISKNAME FREE_GB TOTAL_GB FREE_PERCENTAGE PATH STATE
———– ————— ————— ——— ——— ————— ——————– ————————
0 DATA DATA_0000 27.23 1024.00 2.66 /dev/rhdisk10 NORMAL
1 DATA DATA_0001 27.12 1024.00 2.65 /dev/rhdisk11 NORMAL
2 DATA DATA_0002 27.05 1024.00 2.64 /dev/rhdisk12 NORMAL
……
0 OCR OCR_0000 9.62 10.00 96.21 /dev/rhdisk2 NORMAL
73 rows selected.
SQL> select group_number, name,state,type,total_MB/1024 total_GB,free_mb/1024 FREE_GB,free_mb/total_MB * 100 free_per,(case when free_mb/total_mb * 100 < 15 then ‘*’ else ” end) care from V$ASM_DISKGROUP;
GROUP_NUMBER NAME STATE TYPE TOTAL_GB FREE_GB FREE_PER C
———— —————————— ———– —— ———- ———- ———- –
1 DATA CONNECTED EXTERN 73728 1915.58496 2.59817839 *
2 OCR MOUNTED EXTERN 10 9.62109375 96.2109375

-bash-4.2# ls -l /dev/hdisk1*
brw——- 1 root system 13, 3 Dec 17 2020 /dev/hdisk1
brw——- 1 root system 13, 16 Dec 23 2020 /dev/hdisk10
brw——- 1 root system 13, 14 Dec 23 2020 /dev/hdisk11
brw——- 1 root system 13, 19 Dec 23 2020 /dev/hdisk12
-bash-4.2# ls -l /dev/rhdisk1*
crw——- 1 root system 13, 3 Dec 17 2020 /dev/rhdisk1
crw-rw—- 1 grid asmadmin 13, 16 Sep 28 11:17 /dev/rhdisk10
crw-rw—- 1 grid asmadmin 13, 14 Sep 28 11:17 /dev/rhdisk11
crw-rw—- 1 grid asmadmin 13, 19 Sep 28 11:17 /dev/rhdisk12
crw-rw—- 1 grid asmadmin 13, 8 Sep 28 11:17 /dev/rhdisk13
-bash-4.2# errpt
-bash-4.2# lsattr -El hdisk12 | grep reserve_policy
reserve_policy no_reserve Reserve Policy True
-bash-4.2# lsattr -El hdisk13 | grep reserve_policy
reserve_policy no_reserve Reserve Policy True
-bash-4.2# id oracle
uid=1101(oracle) gid=1000(oinstall) groups=1100(asmadmin),1200(dba),1300(asmdba)
-bash-4.2# id grid
uid=1100(grid) gid=1000(oinstall) groups=1100(asmadmin),1200(dba),1300(asmdba),1301(asmoper)
-bash-4.2#

3. locate the reason: trc shows kfk_debug_get_user_groups: uid:207, euid:1101, gid:1000, egid:1000 (corresponding to dsg user for oinstall genus group, not including asm related genus group)
Trace file /XXX/app/oracle/diag/rdbms/xxx/xxx1/trace/xxx1_ora_9178000.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 – 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
ORACLE_HOME = /XXX/app/oracle/product/11.2/db_2
System name: AIX
Node name: hxdg1
Release: 1
Version: 7
Machine: 00F6E6DC4C00
Instance name: xxx1
Redo thread mounted by this instance: 1
Oracle process number: 194
Unix process pid: 9178000, image: oracle@hxdg1 (TNS V1-V3)

*** 2021-09-28 11:08:13.726
*** SESSION ID:(988.19) 2021-09-28 11:08:13.726
*** CLIENT ID:() 2021-09-28 11:08:13.726
*** SERVICE NAME:(SYS$USERS) 2021-09-28 11:08:13.726
*** MODULE NAME:(oxad@hxdg1 (TNS V1-V3)) 2021-09-28 11:08:13.726
*** ACTION NAME:() 2021-09-28 11:08:13.726

WARNING: failed to open a disk[/dev/rhdisk12]
ORA-15025: could not open disk “/dev/rhdisk12”
ORA-27041: unable to open file
IBM AIX RISC System/6000 Error: 13: Permission denied
Additional information: 3
Additional information: 4
Additional information: 138444804
kfk_debug_get_user_groups: uid:207, euid:1101, gid:1000, egid:1000
WARNING: failed to open a disk[/dev/rhdisk12]
ORA-15025: could not open disk “/dev/rhdisk12″
ORA-27041: unable to open file
IBM AIX RISC System/6000 Error: 13: Permission denied
Additional information: 3
Additional information: 4
Additional information: 138444804
kfk_debug_get_user_groups: uid:207, euid:1101, gid:1000, egid:1000
WARNING: disk locally closed resulting in I/O error
WARNING: Read Failed. group:1 disk:2 AU:893192 offset:16384 size:16384
path:Unknown disk
incarnation:0x4560e025 synchronous result:’I/O error’
subsys:Unknown library iop:0x110db7ed0 bufp:0x110cfde00 osderr:0x0 osderr1:0x0
WARNING: failed to read mirror side 1 of virtual extent 0 logical extent 0 of file 3103 in group [1.374353710] from disk DATA_0002 allocation unit 893192 reason error; if possible, will try another mirror side
DDE rules only execution for: ORA 202
—– START Event Driven Actions Dump —-
—- END Event Driven Actions Dump —-
—– START DDE Actions Dump —–
Executing SYNC actions
—– START DDE Action: ‘DB_STRUCTURE_INTEGRITY_CHECK’ (Async) —–
DDE Action ‘DB_STRUCTURE_INTEGRITY_CHECK’ was flood controlled
—– END DDE Action: ‘DB_STRUCTURE_INTEGRITY_CHECK’ (FLOOD CONTROLLED, 1 csec) —–
Executing ASYNC actions
—– END DDE Actions Dump (total 0 csec) —–
*** 2021-09-28 11:08:13.731
dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x0, level=1, mask=0x0)
—– Error Stack Dump —–
ORA-00202: control file: ‘+DATA/xxx/controlfile/current.257.1062864093.bak’
ORA-15081: failed to submit an I/O operation to a disk
—– Current SQL Statement for this session (sql_id=amdwhucub5mzk) —–
select count(:”SYS_B_0”) from v$dataguard_stats

cat /etc/passwd | grep uid
ps -ef |grep dsg
-bash-4.2# ps -ef | grep dsg
dsg 8455834 2033984 0 09:58:37 – 0:01 sshd: dsg@pts/15
dsg 11405170 11733628 0 12:33:23 – 0:00 /XXX/dsg/aiod/bin/aiod -n 127.0.0.1,45007 -flog /XXX/dsg/aiod/log/log.aiod
root 11536588 13501954 0 13:04:45 pts/28 0:00 grep dsg
root 2033984 3473680 0 09:58:36 – 0:00 sshd: dsg [priv]
dsg 6752538 8455834 0 09:58:37 pts/15 0:00 -ksh
dsg 11733628 1 0 12:33:23 – 0:00 /XXX/dsg/aiod/bin/aiod -n 127.0.0.1,45007 -flog /XXX/dsg/aiod/log/log.aiod

more /XXX/dsg/aiod/log/log.aiod
encrypt_pwd=n # input oracle password is encrypted?
oracle_pdb= # Oracle 12c Instance PDB name
sysdba=n # connect Oracle by SYSDBA?(Y|N)
sysasm=n # connect Oracle by SYSASM?(Y|N)
timeout=6 # recv oxad info timeout minutes. 0 – unused timeout, (0 ~ 254)
standby=A # A – auto check, Y – standby DB, N – not standby DB
[I] 2021-09-28:11:55:49 AOXD XP#5834878 loop startup …
[I] 2021-09-28:11:55:49 asm#21366664 startup(edn:1,rawofs:0) blen(24:4:18)MB 16777216, 149ms
[I] 2021-09-28:11:55:49 ASM APIs startup success! used ASM APIs, 0.17s
[I] 2021-09-28:11:55:49 ASM#21366664 (0,1,255,0) 0, 0.00M, s(0.003s, )
[E] 2021-09-28:11:55:49 AOXD loop err:OXA-1000 OCI for Oracle error -1 occurred at api/sql/execute.c:112, sid xxx1, tns .
ORA-00204: error in reading (block 1, # blocks 1) of control file
ORA-00202: control file: ‘+DATA/xxx/controlfile/current.257.1062864093.bak’
ORA-15081: failed to submit an I/O operation to a disk
Error – OCI_ERROR select count(1) from v$dataguard_stats
[I] 2021-09-28:11:55:49 AOXD service shutdown.
[W] 2021-09-28:11:55:49 Task 0, pid 21366664 exit, (normal exit 0) sleep 30s, and