0

We have Oracle XE 10.2.0.1.0 running on CentOS 6.9.

The Database works stable all the time, except the system reboots. If reboot command is issued in the OS terminal, the Database enters MOUNT mode. Then we issue service oracle-xe restart TWICE to bring the DB to OPEN mode. The first time command issues quickly, and last, the second time it takes some time to restart. As I see in the logs, the first time the instance can not raise up due to some resource blocking. It issues a terminating signal, and then, it starts after the second service oracle-xe restart command issue.

I bring alert_XE.log here

So here is the event and the times:

  1. Fri Oct 21 12:11:46 2022 - First DB starts after reboot, DB enters the MOUNT mode
  2. Fri Oct 21 12:26:50 2022 - First service oracle-xe restart issue
  3. Fri Oct 21 16:51:12 2022 - Second service oracle-xe restart issue, DB enters the OPEN mode

If there is not enough information for giving me the path to the solution, can you write me about where and which logs level I need to increase or what more log I need to watch for missing information.

UPDATE

I fixed the error with LD_LIBRARY_PATH, by editing /etc/init.d/oracle-xe directly, and appended follow line after block of environment variables defenition:

LD_LIBRARY_PATH=$ORACLE_HOME/lib:/lib:/usr/lib
export LD_LIBRARY_PATH

Now, if I try to OPEN database as miracle173 suggests, I get follow error:

ERROR:
ORA-01034: ORACLE not available
ORA-27101: shared memory realm does not exist
Linux Error: 2: No such file or directory

UPDATE

Now we have new errors in alter.log, this is what is going after ALTER DATABASE MOUNT:

Mon Oct 24 17:02:49 2022
Beginning crash recovery of 1 threads
Mon Oct 24 17:02:49 2022
Started redo scan
Mon Oct 24 17:02:49 2022
Completed redo scan
 147 redo blocks read, 78 data blocks need recovery
Mon Oct 24 17:02:49 2022
Started redo application at
 Thread 1: logseq 1791, block 3
Mon Oct 24 17:02:49 2022
Recovery of Online Redo Log: Thread 1 Group 2 Seq 1791 Reading mem 0
  Mem# 0 errs 0: /usr/lib/oracle/xe/app/oracle/flash_recovery_area/XE/onlinelog/o1_mf_2_dgsl2gd0_.log
Mon Oct 24 17:02:49 2022
Completed redo application
Mon Oct 24 17:02:49 2022
Completed crash recovery at
 Thread 1: logseq 1791, block 150, scn 284886106315
 78 data blocks read, 78 data blocks written, 147 redo blocks read
Mon Oct 24 17:02:49 2022
Thread 1 advanced to log sequence 1792
Thread 1 opened at log sequence 1792
  Current log# 1 seq# 1792 mem# 0: /usr/lib/oracle/xe/app/oracle/flash_recovery_area/XE/onlinelog/o1_mf_1_dgsl2dvq_.log
Successful open of redo thread 1
Mon Oct 24 17:02:49 2022
SMON: enabling cache recovery
Mon Oct 24 17:02:50 2022
Successfully onlined Undo Tablespace 1.
Mon Oct 24 17:02:50 2022
SMON: enabling tx recovery
Mon Oct 24 17:02:50 2022
Database Characterset is CL8MSWIN1251
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
Process QMNC died, see its trace file
Mon Oct 24 17:02:51 2022
Errors in file /usr/lib/oracle/xe/app/oracle/admin/XE/udump/xe_ora_2423.trc:
ORA-00443: background process "QMNC" did not start
Mon Oct 24 17:02:51 2022
Errors in file /usr/lib/oracle/xe/app/oracle/admin/XE/udump/xe_ora_2423.trc:
ORA-00450: background process 'QMNC' did not start
ORA-00443: background process "QMNC" did not start
Error 450 happened during db open, shutting down database
USER: terminating instance due to error 450
Instance terminated by USER, pid = 2423
ORA-1092 signalled during: ALTER DATABASE OPEN...

And this is tail of /usr/lib/oracle/xe/app/oracle/admin/XE/udump/xe_ora_2423.trc:

*** 2022-10-24 17:02:49.712
KCRA: start recovery claims for 78 data blocks
*** 2022-10-24 17:02:49.721
KCRA: blocks processed = 78/78, claimed = 78, eliminated = 0
*** 2022-10-24 17:02:49.721
Recovery of Online Redo Log: Thread 1 Group 2 Seq 1791 Reading mem 0
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 1
Average hash chain = 78/78 = 1.0
Max compares per lookup = 1
Avg compares per lookup = 377/377 = 1.0
----------------------------------------------
*** 2022-10-24 17:02:51.204
Process QMNC is dead (pid=2545, state=3):
*** 2022-10-24 17:02:51.204
KSTDUMP: In-memory trace dump
TIME:SEQ#        ORAPID   SID EVENT  OP DATA
========================================================================
8DBD1DEB:0000066E    18    38 10254  34 KSBS1P: process USER trying to start background QMNC
8DBD1DEF:0000066F    18    38 10254  37 KSBS1P: process USER obtained PR enqueue to start background QMNC
8DCC0868:0000067C    18    38 10254  51 KSBS1P: out of loop: process did not start
KSTDUMP: End of in-memory trace dump
*** 2022-10-24 17:02:51.204
ORA-00443: background process "QMNC" did not start
ORA-00450: background process 'QMNC' did not start
ORA-00443: background process "QMNC" did not start

UPDATE

OK, I succeed to connect to MOUNTed instance of DB using oracle account session, I tried ALTER DATABASE OPEN:

[root@MOBILE_TEST bdump]# su - oracle
-bash-4.1$ pwd
/usr/lib/oracle/xe
-bash-4.1$ groups
dba
-bash-4.1$ sqlplus / as sysdba

SQL*Plus: Release 10.2.0.1.0 - Production on Mon Oct 24 17:45:10 2022

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

Connected to an idle instance.

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-01034: ORACLE not available


SQL>

UPDATE

I put logging in oracle-xe:

start() {
        MAXI_LOG="/root/temp/ora.log"
        echo $(date) >> $MAXI_LOG

        if [ "$CONFIGURE_RUN" != "true" ]
        then
        echo "Oracle Database 10g Express Edition is not configured.  You must run '/etc/init.d/oracle-xe configure' as the root user to configure the database."
                exit 0
        fi

        status=`ps -ef | grep tns | grep oracle`
        if [ "$status" == "" ]
        then
                echo "TNSLSTENER" >> $MAXI_LOG
                if [ -f $ORACLE_HOME/bin/tnslsnr ]
                then
                        echo "Starting Oracle Net Listener."
                        $SU -s /bin/bash $ORACLE_OWNER -c "$LSNR  start" > /dev/null 2>&1
                fi
        fi

        echo "Starting Oracle Database 10g Express Edition Instance."
        echo "START" >> $MAXI_LOG
        $SU -s /bin/bash  $ORACLE_OWNER -c "$SQLPLUS -s /nolog @$ORACLE_HOME/config/scripts/startdb.sql" >> $MAXI_LOG 2>&1
        RETVAL=$?

        if [ $RETVAL -eq 0 ]
        then
                echo "GOOD" >> $MAXI_LOG
                echo
        else
                echo Failed to start Oracle Net Listener using $ORACLE_HOME/bin/tnslsnr\
                        and Oracle Express Database using $ORACLE_HOME/bin/sqlplus.
                echo "BAD" >> $MAXI_LOG
                RETVAL=1
        fi

        return $RETVAL
}

I rebooted the system several times, here is what we have in $MAXI_LOG:

25.10.2022 17:31:32 MSK 2022
TNSLSTENER
START
ORACLE instance started.

Total System Global Area  532676608 bytes
Fixed Size                  1259880 bytes
Variable Size             150996632 bytes
Database Buffers          377487360 bytes
Redo Buffers                2932736 bytes
Database mounted.
ORA-01034: ORACLE not available
ORA-27101: shared memory realm does not exist
Linux Error: 2: No such file or directory
GOOD
25.10.2022 17:33:25 MSK 2022
TNSLSTENER
START
ORACLE instance started.

Total System Global Area  532676608 bytes
Fixed Size                  1259880 bytes
Variable Size             150996632 bytes
Database Buffers          377487360 bytes
Redo Buffers                2932736 bytes
Database mounted.
ORA-01034: ORACLE not available
ORA-27101: shared memory realm does not exist
Linux Error: 2: No such file or directory
GOOD

I use ls -t --full-time . | head -10 for see last traces, this is what I have:

[root@MOBILE_TEST ~]# cd /usr/lib/oracle/xe/app/oracle/admin/XE/bdump/
[root@MOBILE_TEST bdump]# ls -t --full-time . | head -10
итого 16780
-rw-r--r--. 1 oracle dba 1906729 2022-10-25 17:33:34.694999956 +0300 alert_XE.log
-rw-r-----  1 oracle dba   39525 2022-10-25 17:02:32.848999960 +0300 xe_lgwr_2361.trc
[root@MOBILE_TEST udump]# ls -t --full-time . | head -10
итого 8976
-rw-r-----  1 oracle dba    3385 2022-10-25 17:33:30.663999958 +0300 xe_ora_2376.trc
-rw-r-----  1 oracle dba    8643 2022-10-25 17:33:27.485999961 +0300 xe_ora_2343.trc
-rw-r-----  1 oracle dba    5126 2022-10-25 17:31:37.601999962 +0300 xe_ora_2385.trc

This is tail of xe_ora_2385.trc:

*** SERVICE NAME:() 2022-10-25 16:34:08.669
*** SESSION ID:(38.1) 2022-10-25 16:34:08.669
kccsga_update_ckpt: num_1 = 8, num_2 = 0, num_3 = 0, lbn_2 = 0, lbn_3 = 0
/usr/lib/oracle/xe/app/oracle/admin/XE/udump/xe_ora_2376.trc
Oracle Database 10g Express Edition Release 10.2.0.1.0 - Production
ORACLE_HOME = /usr/lib/oracle/xe/app/oracle/product/10.2.0/server
System name:    Linux
Node name:      MOBILE_TEST.domain.central
Release:        2.6.32-696.1.1.el6.i686
Version:        #1 SMP Tue Apr 11 16:37:48 UTC 2017
Machine:        i686
Instance name: XE
Redo thread mounted by this instance: 0 <none>
Oracle process number: 18
Unix process pid: 2376, image: oracle@MOBILE_TEST.domain.central (TNS V1-V3)

*** SERVICE NAME:() 2022-10-25 17:33:30.664
*** SESSION ID:(38.1) 2022-10-25 17:33:30.664
kccsga_update_ckpt: num_1 = 8, num_2 = 0, num_3 = 0, lbn_2 = 0, lbn_3 = 0

UPDATE

I set /etc/security/limits.conf:

*          hard    nproc     32768
*          hard    nofile    32768

Logged ulimit in init script:

$SU -s /bin/bash $ORACLE_OWNER -c "ulimit -a | grep '\-[nu]'" >> $ORA_LOG 2>&1

And see, that there is no issue with limits:

Wed Oct 26 17:04:28 MSK 2022
open files                      (-n) 32768
max user processes              (-u) 32768

Also I put Y in /etc/oratab.

But the broblem is still exists...

Improve this question
4
  • Welcome to dba stackexchange
    – Marcello Miorelli
    Oct 21, 2022 at 14:37
  • 1
    what happens if you open the database after the first mount, at Fri Oct 21 12:26:50 2022 by connecting with "sqlplus / as sysdba" and executing an "alter database open;"
    – miracle173
    Oct 21, 2022 at 15:00
  • 1
    "LD_LIBRARY_PATH is not set!". Is your oracle configure correctly? Why is LD_LIBRARY_PATH not set. does ORACLE_HOME point to the correct directory?
    – miracle173
    Oct 21, 2022 at 15:12
  • Please see the update
    – Olga Pshenichnikova
    Oct 24, 2022 at 13:57

1 Answer 1

Reset to default
0

Thank miracle173 for his answer! And thanks to a folk of DBA telegramm group for the help.

So the solution of the problem is very complex, and consist of much different settings. And even though once at fifteen times DB don't starts up. But it is OK for us.

First of all, I started solve error with LD_LIBRARY_PATH. I search solutions over the net, and found this link.

  1. I put NEW LD_LIBRARY_PATH configuration in the .bash_profile
  2. I found OLD LD_LIBRARY_PATH configuration also in /etc/profile

Despite old and new configuration, the system didn't react.

I put logging in /etc/init.d/oracle-xe and /usr/lib/oracle/xe/.bash_profile. Than I saw, that the system simply doesn't treates these files (~/.bash_profile and /etc/profile) during System V Init launch of oracle-xe service.

Then I put the LD_LIBRARY_PATH config in the head of the init script after block of environment variables definition:

LD_LIBRARY_PATH=$ORACLE_HOME/lib:/lib:/usr/lib
export LD_LIBRARY_PATH

I added logging in the startup script, it is very helped me further:

ORA_LOG=/var/log/oracle.log
echo "-------------------------------------------------" >> $ORA_LOG
date >> $ORA_LOG
$SU -s /bin/bash $ORACLE_OWNER -c "ulimit -a | grep '\-[nu]'" >> $ORA_LOG 2>&1

Also I put logging in start as stop functions:

$SU -s /bin/bash  $ORACLE_OWNER -c "$SQLPLUS -s /nolog @$ORACLE_HOME/config/scripts/startdb.sql" >> $ORA_LOG 2>&1
...
$SU -s /bin/bash $ORACLE_OWNER -c "$SQLPLUS -s /nolog @$ORACLE_HOME/config/scripts/stopdb.sql" >> $ORA_LOG 2>&1

I didn't logged listener, thus there wasn't issues with it.

The full final version of init script is here

Further I handled problems with system limits. As you see I also logged the ulimit -a in the head of the init script. I configured system limits in /etc/security/limits.conf:

*          hard    nproc     32768
*          hard    nofile    32768

Now we can see further messages in /var/log/oracle.log:

-------------------------------------------------
Wed Oct 26 17:20:58 MSK 2022
open files                      (-n) 32768
max user processes              (-u) 32768

The last fix I did, is "step by step initialization". I changed the $ORACLE_HOME/config/scripts/startdb.sql file from:

connect / as sysdba
startup
exit

To:

connect / as sysdba
startup nomount
alter database mount;
alter database open;
exit

So this is final record in our new log:

-------------------------------------------------
Thu Oct 27 13:26:01 MSK 2022
open files                      (-n) 32768
max user processes              (-u) 32768
START
ORACLE instance started.
Total System Global Area  532676608 bytes
Fixed Size                  1259880 bytes
Variable Size             150996632 bytes
Database Buffers          377487360 bytes
Redo Buffers                2932736 bytes
Database altered.
Database altered.
Improve this answer

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.