Wednesday, October 10, 2018

adoacorectl.sh exiting with status 204

After server rebooted unexpectedly, adoacorectl.sh failed to start OACORE OC4J due to opmn issue and made R12.1.3 initial page unable to re-direct to login page. The error is

adoacorectl.sh: exiting with status 204

File $INST_TOP/logs/appl/admin/log/adoacorectl.txt shows more detail:
10/09/18-11:37:25 :: adoacorectl.sh version 120.13
10/09/18-11:37:25 :: adoacorectl.sh: starting OPMN if it is not running
opmnctl: opmn is already running.
10/09/18-11:37:25 :: adoacorectl.sh: Starting OPMN managed OACORE OC4J instance
opmnctl: starting opmn managed processes...
============================================
opmn id=
hostname.domian.com:6240
    0 of 1 processes started.

ias-instance id=EBSDEV_hostname.hostname.domian.com
++++++++++++++++++++++++++++++++++++++++++++
ias-component/process-type/process-set:
    default_group/oacore/default_group/

Error
--> Process (index=1,uid=1230729787,pid=17205)
    failed to start a managed process after the maximum retry limit
    Log:
   $INST_TOP/logs/ora/10.1.3/opmn/default_group~oacore~default_group~1.log

10/09/18-11:37:37 :: adoacorectl.sh: exiting with status 204

File $INST_TOP/logs/ora/10.1.3/opmn/default_group~oacore~default_group~1.log has below warning which was not new and existed before:
--------
18/10/09 11:37:25 Start process
--------
18/10/09 11:37:26 WARNING: ApplicationLogManager is not installed, may result in loader leaks. Set -Djava.util.logging.manager=oracle.classloader.util.ApplicationLogManager


I did not make any changes in EBS in past months. Seems the problem was with opmn, but I do not know what it is. So I just ran autocofig. After that, "adoacorectl.sh start" worked surprisingly and login page showed up. The warning message with ApplicationLogManager still stays in the opmn log file.

The problem could be some session lock files got inconsistent by the server crash.

BTW, to turn trace (increase logging) on OC4J oacore by editing two files:

Edit j2ee-logging.xml adjust the following in file:
$ORA_CONFIG_HOME/10.1.3/j2ee/oacore/config/j2ee-logging.xml
<logger name=’oracle’ level='TRACE:32′ useParentHandlers=’false’>
Edit orion-web.xml adjust the following in file:
$ORA_CONFIG_HOME/10.1.3/j2ee/oacore/application-deployments/oacore/html/orion-web.xml
<param-name>debug_mode</param-name>
<param-value>true</param-value>
But it is difficult to read and understand the log log.xml under $LOG_HOME/ora/10.1.3/j2ee/oacore/oacore_default_group_1

Wednesday, September 19, 2018

Find the NLS settings on a connection

When making a connection to the database, below query will tell its process IDs on both client and db server:

SQL> select b.sid, b.serial#, a.spid processid, b.process clientpid
from v$process a, v$session b
where a.addr = b.paddr
and b.audsid = userenv('sessionid');

       SID    SERIAL#  PROCESSID   CLIENTPID
------------ ------------  ----------------    -----------------
       180      42146      48824530         26093
26093 is the process ID for this sqlplus session on client/Apps side.
48824530 is the process ID on database server for this session.

In general,
V$SESSION.SID and V$SESSION.SERIAL#  – process ID in database
V$PROCESS.SPID – Shadow process ID on the database server
V$SESSION.PROCESS – Client process ID

If start a new session on the same client where sqlplus is still running, you can verify it is running:
$ ps -ef | grep 26093
ebsdev  26093 25836  0 15:09 pts/1    00:00:00 sqlplus

To find what NLS settings are used to support the connection, run below lines:
$ ps ewww 26093 | tr ' ' '\n' | grep NLS
-DNLS_ASIA
FORMS_OVERRIDE_ENV=NLS_LANG,NLS_NUMERIC_CHARACTERS,NLS_SORT,NLS_DATE_LANGUAGE,NLS_DATE_FORMAT,FORMS_USER_DATE_FORMAT,FORMS_USER_DATETIME_FORMAT,FORMS_OUTPUT_DATE_FORMAT,FORMS_OUTPUT_DATETIME_FORMAT,FORMS_ERROR_DATE_FORMAT,FORMS_ERROR_DATETIME_FORMAT,FORMS_TZFILE,FORMS_DATETIME_SERVER_TZ,FORMS_DATETIME_LOCAL_TZ,FORMS_USER_CALENDAR
NLS_DATE_FORMAT=DD-MON-RR
NLS_DATE_LANGUAGE=
NLS_LANG=American_America.WE8ISO8859P1
NLS_NUMERIC_CHARACTERS=.,
NLS_SORT=BINARY
ORA_NLS10=$ORACLE_HOME/nls/data/9idata

Do the same for other sessions. For example, if you are interested on the listener session, find its process ID first and then see its NLS settings by "ps ewww".
$ ps -ef|grep tnslsnr
ebsdev  23845     1  0 Aug01 ?        00:00:00 $ORACLE_HOME/bin/tnslsnr APPS_EBSDEV -inherit

Similarly, you can do the same with 48824530 on database server to find its NLS settings.

$ ps ewww 48824530 | tr ' ' '\n' | grep NLS
NLS_LANG=AMERICAN_AMERICA.WE8ISO8859P1
NLSPATH=/usr/lib/nls/msg/%L/%N:/usr/lib/nls/msg/%L/%N.cat
ORA_NLS10=$ORACLE_HOME/nls/data/9idata

Below query can help to find parameters for database characterset. Ideally all of three sides shall be consistent.

SQL> SELECT db.parameter as parameter, db.value as database_value,
s.value as session_value,  i.value as instance_value
FROM
nls_database_parameters db
LEFT JOIN
nls_session_parameters s
ON s.parameter = db.parameter
LEFT JOIN
nls_instance_parameters i
ON i.parameter = db.parameter
ORDER BY parameter;

PARAMETER DATABASE_VALUE SESSION_VALUE INSTANCE_VALUE
------------------ ------------------------- ------------------------- -------------------
NLS_CALENDAR GREGORIAN GREGORIAN
NLS_CHARACTERSET WE8ISO8859P1
NLS_COMP BINARY BINARY binary
NLS_CURRENCY $ $
NLS_DATE_FORMAT DD-MON-RR DD-MON-RR DD-MON-RR
NLS_DATE_LANGUAGE AMERICAN AMERICAN
NLS_DUAL_CURRENCY $ $
NLS_ISO_CURRENCY AMERICA AMERICA
NLS_LANGUAGE AMERICAN AMERICAN AMERICAN
NLS_LENGTH_SEMANTICS BYTE BYTE BYTE
NLS_NCHAR_CHARACTERSET AL16UTF16
NLS_NCHAR_CONV_EXCP FALSE FALSE FALSE
NLS_NUMERIC_CHARACTERS ., ., .,
NLS_RDBMS_VERSION 12.1.0.2.0
NLS_SORT BINARY BINARY binary
NLS_TERRITORY AMERICA AMERICA america
NLS_TIMESTAMP_FORMAT DD-MON-RR HH.MI.SSXFF AM DD-MON-RR HH.MI.SSXFF AM
NLS_TIMESTAMP_TZ_FORMAT DD-MON-RR HH.MI.SSXFF AM DD-MON-RR HH.MI.SSXFF AM TZR TZR
NLS_TIME_FORMAT HH.MI.SSXFF AM HH.MI.SSXFF AM
NLS_TIME_TZ_FORMAT HH.MI.SSXFF AM TZR HH.MI.SSXFF AM TZR

When NLS_LANG is unset, it defaults to US7ASCII.

Without proper setting on ORA_NLS10, package UTL_FILE may not work correctly. See https://erpondb.blogspot.com/2016/10/troubleshhot-utlfile-error.html

Saturday, September 15, 2018

"deleted" files still take disk space

We received alerts on disk space used by EBS is 97% full. When I use "du" to check the space, it shows only 60% of the space is used. But "df -h" shows it is 97% full. The problem is that some files deleted by EBS process will not really release the space back yet until the process is stopped. See https://access.redhat.com/solutions/2316

Below line will find if there are "deleted" files that still hold space, assuming the partition is /u02/app:

$ lsof | grep /u02/ | grep app | grep delete | more
rwrun     18759   applMgr   13u      REG              253,3 3140558848    3082366 $INST_TOP/temp/dat000418759 (deleted)
rwrun     18759   applMgr   15u      REG              253,3  745730048    3082368 $INST_TOP/temp/idx000518759 (deleted)
rwrun     18759   applMgr   17u      REG              253,3          0    3082375 $INST_TOP/temp/000718759 (deleted)

3140558848 is the size by the file. You may see the size is increasing if process 18759 keeps running. But you will not see the file by "ls" command.

$ ps -ef | grep 18759
$ORACLE_HOME/bin/rwrun mode=character ARRAYSIZE=5 P_CONC_REQUEST_ID=21334937 P_MAIL_INDICATOR='ALL' report=$APPL_TOP/aear/reports/US/XXXXRREG.rdf userid=APPS batch=yes destype=file desname=$APPLCSF/out/o21334937.out desformat=$FND_TOP/reports/PD pagesize=2050x66

We found concurrent report "XXXX Receipt Register" in request ID 21334937 ran for 15 hours. After it is cancelled, the "hidden" space is released back.

The same problem happens to /tmp file partition, when parameter forms_tmpdir points to /tmp.

$ grep forms_tmpdir $CONTEXT_FILE
         <forms_tmpdir oa_var="s_forms_tmpdir" osd="UNIX">/tmp</forms_tmpdir>

$ lsof | grep /tmp | grep delete   <== it takes longer
$ lsof /tmp | grep delete             <== it runs quick

frmweb      398              applMgr    86u      REG              253,5    5303826        365 /tmp/filer6nHW3.TMP (deleted)
frmweb      570              s044150   86u      REG              253,5   41307666        144 /tmp/file4FWO2C.TMP (deleted)

$ ps -ef | grep 570
applMgr     570 31251  0 Mar15 ?        00:07:39 frmweb server webfile=HTTP-0,0,1,default

It is better to change forms_tmpdir to $APPLTMP, $INST_TOP/temp or $NE_BASE/EBSapps/log. /tmp is for server logs and if it is full, the server may crash and go down.

Tuesday, September 11, 2018

FND: Diagnostics to find the true error

After log onto EBS R12.1.3 homepage, click on Preferences and get a generic error:

You have encountered an unexpected error. Please contact the System Administrator for assistance.

The error seems just on one page, not on all pages. I had the same error message before when the database having issue, such as invalid package. But the error does not tell what is the real cause.

The key is to enable Profile option "FND: Diagnostics". After re-login, the error message will come with a link "Click here for exception details"





That leads to find the true error is an ORA-00600 error on SQL statement:

SELECT * FROM (select t.territory_short_name territory_name, t.nls_territory
from   fnd_territories_vl t, v$nls_valid_values v
where  t.nls_territory = v.value
and    v.parameter = 'TERRITORY') QRSLT  ORDER BY territory_name
;
ORA-00600: internal error code, arguments: [1350], [3], [23], [60], [AMERICAN], [0], [], [], [], [], [], []

Thursday, August 16, 2018

EBS hits ORA-28040: No matching authentication protocol

After database was upgraded to 12.1.0.2, clone script to refresh a R12.1.3 instance got a error:

$ perl adcfgclone.pl appsTier
... ...
Target System Port Pool [0-99] : 27
Checking the port pool 27
done: Port Pool 27 is free
Report file located at $INST_TOP/admin/out/portpool.lst
Complete port information available at $INST_TOP/admin/out/portpool.lst
RC-40201: Unable to connect to Database EBSQA.


The detail error messages in log file are

---------------------------------------------------------------
                   ADX Database Utility
---------------------------------------------------------------

getConnectionUsingAppsJDBCConnector() -->
    APPS_JDBC_URL=''
    Trying to get connection using SID based connect descriptor
getConnection() -->
    sDbHost    : ebsdb1q
    sDbDomain  : domain.com
    sDbPort    : 1527
    sDbSid     : EBSQA
    sDbUser    : APPS
    Trying to connect using SID...
getConnectionUsingSID() -->
    JDBC URL: jdbc:oracle:thin:@ebsdb1q.domain.com:1527:EBSQA
    Exception occurred: java.sql.SQLException: ORA-28040: No matching authentication protocol

    Trying to connect using SID as ServiceName
getConnectionUsingServiceName() -->
    JDBC URL: jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=ebsdb1q.domain.com)(PORT=1527))(CONNECT_DATA=(SERVICE_NAME=EBSQA)))
    Exception occurred: java.sql.SQLException: ORA-28040: No matching authentication protocol

    Trying to connect using SID as ServiceName.DomainName
getConnectionUsingServiceName() -->
    JDBC URL: jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=ebsdb1q.domain.com)(PORT=1527))(CONNECT_DATA=(SERVICE_NAME=EBSQA.domain.com)))
    Exception occurred: java.sql.SQLException: Listener refused the connection with the following error:
ORA-12514, TNS:listener does not currently know of service requested in connect descriptor
The Connection descriptor used by the client was:
(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=ebsdb1q.domain.com)(PORT=1527))(CONNECT_DATA=(SERVICE_NAME=EBSQA.domain.com)))

    Connection could not be obtained; returning null
-------------------ADX Database Utility Finished---------------
Exception occurred while preseeding variables in the context file: java.sql.SQLException: Could not get connection to the database

StackTrace:
java.sql.SQLException: Could not get connection to the database


Because of the error, it failed to generate TNS files:

##########################################################################
                   Generate Tns Names
##########################################################################
Logfile:  $INST_TOP/admin/log/NetServiceHandler.log
Classpath: $COMMON_TOP/java/lib/appsborg2.zip:$COMMON_TOP/java/classes

Updating s_tnsmode to 'generateTNS'
UpdateContext exited with status: 0
AC-50480: Internal error occurred: java.lang.Exception: Error while generating listener.ora.
Error generating tnsnames.ora from the database, temporary tnsnames.ora will be generated using templates
Instantiating Tools tnsnames.ora
Tools tnsnames.ora instantiated
Web tnsnames.ora instantiated

adgentns.pl exiting with status 2
ERRORCODE = 2 ERRORCODE_END
.end std out.

.end err out.
Result             : FAILED

It seems next steps in the clone script use Sqlplus to make database connection and make this error ignorable. So, even with the error, the cloned instance worked fine.

To avoid this JDBC error, before running the clone script, add two lines to file $TNS_ADMIN/sqlnet.ora on database server and then bounce database listener (Doc. 2125856.1):
SQLNET.ALLOWED_LOGON_VERSION_CLIENT=8
SQLNET.ALLOWED_LOGON_VERSION_SERVER=8

The setting 8 (or 10, 11) has nothing to do with the Oracle database version, it is authentication level used by the JDBC. But, it is a temporary solution, because it leads to use old and unsupported Oracle drivers. The best solution though is to upgrade the Oracle driver on client side.

One solution after the clone worked is to customize file $ORA_CONFIG_HOME/10.1.3/j2ee/forms/config/server.xml with using two .jar files in $COMMON_TOP/java/lib.

I did not test the solution by Doc. 2228803.1 which will modify Perl script to use two newer .jar files.

If clone script does not get error, the log should like this:

---------------------------------------------------------------
                   ADX Database Utility
---------------------------------------------------------------

getConnection() -->
    sDbHost    : ebsdb1q
    sDbDomain  : domain.com
    sDbPort    : 1547
    sDbSid     : EBSQA
    sDbUser    : APPS
    Trying to connect using SID...
getConnectionUsingSID() -->
    JDBC URL: jdbc:oracle:thin:@ebsdb1q.domain.com:1547:EBSQA
    Connection obtained

-------------------ADX Database Utility Finished---------------