One of our Avaloq Databases crashed with the following information in the alert log:

Wed Mar 02 19:10:22 2016
PMON (ospid: 26747): terminating the instance due to error 471
Wed Mar 02 19:10:23 2016
System state dump requested by (instance=1, osid=26747 (PMON)), summary=[abnormal instance termination].
System State dumped to trace file /u00/oracle/orabase/diag/rdbms/ora5prim/ORA5/trace/ORA5_diag_26774_20160302191023.trc
Instance terminated by PMON, pid = 26747

Contents of the Pmon trace file:

Background process DBW0 found dead
Oracle pid = 10
OS pid (from detached process) = 26780
OS pid (from process state) = 26780
dtp = 6001ba70, proc = 3a46b1428

Assuming DBW0 died there should be some information in the dbw trace file. Unfortunately there was nothing about the crash in the trace file. So DBW0 crashed without leaving any trace information. How is this possible? After searching the Oracle Metalink for any bugs which might be related to the case I remembered that we had problems in the past where Avaloq accidentally killed a critical Oracle process.

So I checked the OS Audit logs:

 exec_args,3,/usr/bin/ksh,/u00/oracle/orabase/admin/ORA9/asmd/bin/modelcache.sh,stop
 subject,900074,1000,1000,1000,1000,21383,1709692623,4728 5632 workstation2.domain.company
 return,success,0
 zone,orahost02t
 header,229,2,execve(2),,svglb56t,2016-03-02 19:10:22.526 +01:00
 path,/zones/orahost02t/root/usr/bin/cat
 attribute,100555,root,bin,65616,201861,18446744073709551615
 exec_args,2,cat,/u00/oracle/orabase/admin/ORA9/asmd/var/modelcache_0.pid
 subject,900074,1000,1000,1000,1000,21386,1709692623,4728 5632 workstation2.domain.company

So modelcache.sh was executed with the “stop” parameter and it was reading the following file:/u00/oracle/orabase/admin/ORA9/asmd/var/modelcache_0.pid

So what does this script do when using the stop parameter:

eval PID=`cat $PIDFILE`
 if [ "$?" = 0 ]; then
 ps -p $PID > /dev/null 2>&1
 if [ "$?" = 0 ]; then
 #Slave is running. Terminate.
 kill -9 $PID
 rm $PIDFILE

After reading the PID from the Pidfile it terminates the process with “kill -9”.  The script does not verify whether the slave process belongs to it or not. Now what happens if the slave is dead already and another process got this PID? The script will terminate that process.

Although the Pidfile was already deleted I was able to restore it:

$cat /u00/oracle/orabase/admin/ORA9/asmd/var/modelcache_0.pid
 26780

So the script killed the process with PID 26780 which was the DBW0 process at that time. That explains why there was no information about the crash in the dbw0 trace file.

BugFix from Avaloq:

Avaloq modified the modelcache script to include a function which verifies the process creation date by issuing the “ls -ld /proc/$PID” command. With this fix it is not possible anymore that the script kills the wrong process.