Tuesday, March 23, 2010

TNS 12521: No message file for product=RDBMS, facility=ORA

Hi,
We came across an interesting issue over the weekend. After the cold backup of the database, we were not able to connect to the db from any of the apps front end servers using sqlplus. Due to this all the FE services including concurrent managers were down. Most recently we had performed some autoconfig related maintenance activity. We were seeing the following error message while trying to connect from sqlplus:
ORA-12521 No message file for product=RDBMS, facility=ORA

Following is the error logged in sqlnet.ora file:
Fatal NI connect error 12514, connecting to: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=trm.domain.com)(PORT=1682))(CONNECT_DATA=SERVICE_NAME=kvprod.domain.com)(INSTANCE_NAME=kvprod)(CID=(PROGRAM=)(HOST=11-am-11)(USER=oakvprod))))
VERSION INFORMATION:
TNS for Linux: Version 8.0.6.0.0 - Production
TCP/IP NT Protocol Adapter for Linux: Version 8.0.6.3.0 - Production Time: 21-MAR-10 09:56:41 Tracing not turned on.
Tns error struct:
nr err code: 12204
TNS-12204: TNS:received data refused from an application
ns main err code: 12564
TNS-12564: TNS:connection refused ns secondary err code: 0 nt main err code: 0 nt secondary err code: 0 nt OS err code: 0

Following is the error in listener log file on db host:
21-MAR-2010 08:15:42 * (CONNECT_DATA=(SERVICE_NAME=kvprod.domain.com)(INSTANCE_NAME=kvprod)(CID=(PROGRAM=)(HOST=11-am-11)(USER=oakvprod))) * (ADDRESS=(PROTOCOL=tcp)(HOST=145.254.224.149)(PORT=54806)) * establish * KVPROD.domain.com * 12521

The lsnrctl status command showed the following output:
LSNRCTL> Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=trm.domain.com)(PORT=1682))(CONNECT_DATA=(SID=KVPROD)))
STATUS of the LISTENER------------------------Alias KVPROD
Version TNSLSNR for HPUX: Version 9.2.0.7.0 - Production
Start Date 21-MAR-2010 10:01:27Uptime 0 days 0 hr. 30 min. 35 secTrace Level offSecurity OFFSNMP OFFListener Parameter File /oracle/product/9.2.0.7/KVPROD/network/admin/KVPROD_trm/listener.ora
Listener Log File /oracle/product/9.2.0.7/KVPROD/network/admin/KVPROD.logListening Endpoints Summary... (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROCKVPROD))) (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=trm.domain.com)(PORT=1682)))
Services Summary...
Service "KVPROD" has 1 instance(s). Instance "KVPROD", status UNKNOWN, has 1 handler(s) for this service...
Service "KVPROD.domain.com" has 1 instance(s). Instance "/usr/tools/oracle/scripts/KVPROD", status READY, has 1 handler(s) for this service...
Service "PLSExtProc" has 1 instance(s).
Instance "PLSExtProc", status UNKNOWN, has 1 handler(s) for this service...
The command completed successfully

That is where we observed that the Instance registered with the listener was reflecting as /usr/tools/oracle/scripts/KVPROD.

Further troubleshooting led me to figure out that instance name parameter was reflecting as /usr/tools/oracle/scripts/KVPROD.

SQL> show parameter instance_name
/usr/tools/oracle/scripts/KVPROD

Further analysis revealed that this anomaly is due to the environment variable called ORACLE_PATH. If the ORACLE_PATH is set and if there is a file or folder by the same name as ORACLE_SID, then oracle apparently concludes on instance_name as $ORACLE_PATH$ORACLE_SID. That, in the absence of instance_name init parameter set explicitly in init file. If instance_name init parameter is set, this parameter takes precedence over the calculated value.

In our case, we did not have the instance_name parameter set in init file and we had a folder by the same name as that of ORACLE_SID in the oracle_path which led to this issue.
Fix:
1. Set instance_name parameter explicitly
OR
2. unset ORACLE_PATH
OR
3. Do not have a file/folder by the same name as that of oracle_sid in oracle_path

Why this setting took effect after the last bounce, why not in the past? - always the last maintenance activity is a suspect. It may have brought in the oracle_path variable. Just that file/folder with name same as that of sid not being there in any dev/test envs but being present on PROD is good enough to nullify hours and hours of trial runs which happen before we make the change in production!!
- Aravind Kamath Posral

Thursday, March 11, 2010

IBY_0001 Communication error. The payment system, the processor, or iPayment electronic commerce servlet is not available/accessible.

IBY_0001 Communication error. The payment system, the processor, or iPayment electronic commerce servlet is not available/accessible. Please make sure you have the correct system set up and resubmit the request at a later time.

Problem:
In our Oracle applications instance R11i (11.5.8), we applied some patches as part of some maintenance activity. Subsequently we ran autoconfig and then, the users complained that their iPayment credit card authorizations were failing with the aforesaid error.

Troubleshooting and Fix:
I am aware that the error message is generic in nature and can happen due to a variety of reasons including misconfiguration of payment gateway related class files in jserv.properties / zone.properties / System setup using iPayment Administrator responsibility and so on. However, in our case, we did not have a reason to suspect those factors as the change that happened was we having applied some patches and DBA related maintenance activities.

The first thing to do in this kind of a situation is to enable FND Debug Logs. Specify a location for the log file and provide the module which needs to be traced, in our case IBY.
Second thing is enable AF logs by having debug related entries in jserv.properties:
wrapper.bin.parameters=-DAFLOG_ENABLED=TRUE
wrapper.bin.parameters=-DAFLOG_MODULE=iby%
wrapper.bin.parameters=-DAFLOG_LEVEL=STATEMENT
wrapper.bin.parameters=-DAFLOG_FILENAME=/tmp/fndLog10Mar.log

However, I believe it is a good option to enable debug logging in jserv by editing jserv.properties and editing log related parameters :
log=truelog.file=[full path to jserv.log]
log.timestamp = true
log.channel.debug=true
Dont forget to enable debug logging in httpd.conf. This should also be able to trap the error.

The above debug settings resulted in the following error stack (Partial Error Stack):
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:350)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:137)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:124)
at java.net.Socket.(Socket.java:268)
at java.net.Socket.(Socket.java:95)
at oracle.apps.iby.payment.PmtAdapter._oraMippSocket(PmtAdapter.java:982)
at oracle.apps.iby.payment.VendorAdapter.oraMipp(VendorAdapter.java:146)
at oracle.apps.iby.payment.VendorAdapter.oraDispatch(VendorAdapter.java:396)
at oracle.apps.iby.payment.VendorAdapter.oraDispatch(VendorAdapter.java:328)

This resulted in analyzing why the connection refused error was showing up.
It turns out that the parameter "Listen" in httpd.conf got updated due to new templates brought in by the patch.

Before patch it was :
Listen 8001
After patch it was:
Listen [Hostname.domain.com]:8001

This was the cause of this issue.

When you have the Listen 8001 directive, the apache listens on 127.0.0.1. However, when Listen [Hostname.domain.com]:8001 is configured, then it listens on the hostname. So if the iPayment uses a load balancer URL, it will not be able to connect because in the /etc/hosts file on the physical host, the entry will look like:
127.0.0.1 http://www.qcprod.acme.com/
So, when the loop back connection from the host tries to connect on 127.0.0.1, because apache is no longer listening on 127.0.0.1 and hence it sees connection refused error, which results in the original error message thrown by iPayment. The fix is to change the Listen parameter back to original value.
- Aravind Kamath Posral