Monday, March 14, 2016

Enable Forms Runtime Diagnostics (FRD)

1. R12.1 Forms can be implemented in servlet mode or socket mode. Check file $FORMS_WEB_CONFIG_FILE (or $INST_TOP/ora/10.1.2/forms/server/appsweb.cfg) to find which mode forms runs:

In Servlet mode:
serverURL=/forms/lservlet
connectMode=servlet    

In Socket mode:
serverURL=(should be blank)
connectMode=Socket

This can be also verified by Profile option "ICX: Forms Launcher" value https://hostname.domain:port/forms/frmservlet on site level.

2. Doc ID 438652.1 ( R12: Forms Runtime Diagnostics (FRD), Tracing And Logging For Forms In Oracle Applications) gives ways to capture all events that occur in a form session. Unfortunately if the forms does launch, no trace log will be generated. I tested three ways in R12.1.

1) To enable FRD on Site level:
In appsweb.cfg, set "record=collect" as shown below (under ENVIRONMENT SPECIFIC PARAMETERS section)

# Sub argument for other params
record=collect

also can specify the log name
log=site1.log 

2) To enable FRD on User level:
Change Profile option "ICX: Forms Launcher" on user level to https://hostname.domain:port/forms/frmservlet?record=collect

Then, launch forms after logging onto EBS (usually without any services downtime, but may need to bounce Apache or clear cache). Forms shall popup a note "Forms Runtime Diagnostics is enabled, Please note this can affect performance." before forms shows up.

By default, trace file collect_<pid> gets written in folder $FORMS_TRACE_DIR, where <pid> is the process identifier.  "grep" the pid to find which os process created it.

Optionally, in appsweb.cfgs, specify the log name
log=user1.log
(Note: Log file site1.log or user1.log will be saved in folder $FORMS_TRACE_DIR. This folder may need manually cleaning from time to time.)

3) Enabling FRD (in R12.1) by URL https://hostname.domain:port/forms/frmservlet?record=collect ( or https://hostname.domain:port/forms/frmservlet?record=collect+log=user1.log )
Enter EBS userID/password to access forms directly. But it may give error:
APP-FND-01542: This Applications Server is not authorized to access this database.

To get this working, modify current context file by changing “s_appserverid_authentication” value from SECURE to OFF. Then shutdown apps and run Autoconfig.

3. When QA uses Vugen 12 for scripting and uses HP Performance Center (PC) 12 to run the scripts to test EBS R12.1.3 site performance, I was asked to change Profile option "ICX: Forms Launcher" on user level from https://hostname.domain:port/forms/frmservlet to
https://hostname.domain:port/forms/frmservlet?play=&record=names

I did not know what that profile value really does. But after the change, performance testing worked by PC 12 for our QA.

NOTES:  For JWS, do NOT use Method 2 of Option 1 in Doc ID 438652.1 or follow Doc ID 373548.1 (How To Collect And Use Forms Trace (FRD) in Oracle Applications Release 12) to enable FRD by setting up profile option Forms Runtime Parameters to "record=forms tracegroup=0-97". It will give error "FRM-90926: Duplicate Parameter on Command Line" without launching forms.

Tuesday, March 8, 2016

Name a URL for EBS website (and F5)

After EBS is installed and configured on host webHost1d, the default URL is http://webHost1d.domain.com:s_webport. Most times, we want to replace it with more meaningful name, such as finance.domain.com. Or if multiple nodes for the web/form tier, a DNS name has to be used for the EBS site.

1. Request a DNS ip address for finance.domain.com

DNS ip address registration will map server webHost1d.domain.com (or additional server) to finance.domain.com. Before the mapping, you can not ping finance.domain.com or nslookup finance.domain.com.

$ nslookup finance.domain.com
** server can't find finance: SERVFAIL

$ ping finance.domain.com
ping: unknown host finance.domain.com

2. After the DNS ip is registered, nslookup will work like something below. Here, 123.45.67.987 is the ip address for finance.domain.com

$ nslookup finance.domain.com
Server:         123.45.67.89
Address:      123.45.67.89#53

finance.domain.com       canonical name = webHost1d.domain.com.
Name:   webHost1d.domain.com
Address: 123.45.67.987

If finance.domain.com is monitored by F5, its DNS ip address will tied to multiple pool members inside F5, depending on the number of EBS web/forms nodes. In this case, nslookup will return slightly different:

$ nslookup finance.domain.com
Server:         123.45.67.89
Address:      123.45.67.89#53

finance.domain.com        canonical name = finance.dev.vip.domain.com.
Name:   finance.dev.vip.domain.com
Address: 123.45.67.987

The DNS entry for finance.domain.com pints the F5 CNAME  finance.dev.vip.domain.com

3. Also, ping on it shall also work

$ ping finance.domain.com
PING finance.domain.com (123.45.67.987) 56(84) bytes of data.
64 bytes from finance.domain.com (123.45.67.987): icmp_seq=1 ttl=63 time=0.280 ms
64 bytes from finance.domain.com (123.45.67.987): icmp_seq=2 ttl=63 time=0.559 ms

4. Make 3 changes in $CONTEXT_FILE to use finance.domain.com as the URL.

<externURL oa_var="s_external_url">https://webhost1d.domain.com:4453</externURL>  =>
<externURL oa_var="s_external_url">https://finance.domain.com:4453</externURL>

<webentryhost oa_var="s_webentryhost">webhost1d</webentryhost>  =>
<webentryhost oa_var="s_webentryhost">finance</webentryhost>

<login_page oa_var="s_login_page">https://webhost1d.domain.com:4453/OA_HTML/AppsLogin</login_page>   =>
<login_page oa_var="s_login_page">https://finance.domain.com:4453/OA_HTML/AppsLogin</login_page>

After AutoConfig, the EBS site can be accessed by https://finance.domain.com:4453

By the way, when 4453 is the ssl port number, it will be the value for three $CONTEXT_FILE variables (and also in $INST_TOP/ora/10.1.3/Apache/Apache/conf/ssl.conf file as the Listen port):

<httpslistenparameter oa_var="s_https_listen_parameter">4453</httpslistenparameter>
<web_ssl_port oa_var="s_webssl_port" oa_type="PORT" base="4443" step="1" range="-1" label="Web SSL Port">4453</web_ssl_port>
<activewebport oa_var="s_active_webport" oa_type="DUP_PORT" base="8000" step="1" range="-1" label="Active Web Port">4453</activewebport>

TROUBLESHHOTING

After an EBS R12.1.3 instance was cloned / moved to new nodes (webHost1d and webHost2d), EBS site page https://finance.domain.com:4453 did not work. 

Page using node name http://webHost1d.domain.com:s_webport worked but failed on re-directing to login page (Note: if company network does not allow http, this page may not load up in browser. Then, on OS level, try $ wget webHost1d.domain.com 8021 ). So, Apache services worked fine. Furthermore, TELNET to the node link works (if telnet is not available, try "wget"): 

$ telnet webHost1d.domain.com 8021
Trying 177.99.88.66...
Connected to xifsapw3q.
Escape character is '^]'.
GET       <== type in/Enter
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<HTML><HEAD>
<TITLE>400 Bad Request</TITLE>
</HEAD><BODY>
<H1>Bad Request</H1>
Your browser sent a request that this server could not understand.<P>
invalid request-URI <P>
</BODY></HTML>
Connection closed by foreign host.


While using NSLOOKUP to check the site, it returns two IPs:

$ nslookup finance.domain.com   <== It returns two entries
Server:         123.45.67.89
Address:      123.45.67.89#53

finance.domain.com        canonical name = finance.dev.vip.domain.com.
Name:   finance.dev.vip.domain.com
Address: 123.45.67.987
Name:   finance.dev.vip.domain.com
Address: 123.45.66.987

The problem was in F5. After F5 admin removed and re-entered two pool members' IPs, and also re-entered port number (web_ssl_port 4453) in F5 tool, the problem got fixed. F5 admin said the problem was on the port number (s_webport 8021??). If s_webport is listened in F5, webpage https://finance.domain.com:4453 may give ERR_CONNECTION_RESET error 

If 443 is used as s_active_webport (vs. 4453) in $CONTEXT_FILE, 443 shall be also entered in F5 to make site https://finance.domain.com work.

By the way, if EBS site https://finance.domain.com works, URL to single node  https://webHost1d.domain.com:web_ssl_port shall say "This site is not secure" or "Your connection is not private" (or ERR_CERT_COMMON_NAME_INVALID, maybe because the ssl cert is not for webHost1d.domain.com).

Another common issue in network is IP address is not mapping to the DNS name, for example: 

$ nslookup  123.45.67.987 
** server can't find 123.45.67.987.in-addr.arpa: NXDOMAIN



Thursday, March 3, 2016

Get active session info in EBS database

When an EBS job or session runs too long, everyone wants to know what it is doing in the database (11g & 12c) and how far away from its finish. Depending on the session stage, if the job is actively processing sql statements, two scripts here will provide similar Output:
... ... ...
Progress in DB (SID: 3258)
----------------------------------------------------------
START TIME ...... : 08-FEB-2016 15:00:54
Elapsed in min .... : 0:11
Remaining ......... : 0:3
Complete_pct .... : 79.59

SQL ID .......... : f8h3xq0c5sqb6
SQL hash value .. : 408705382
db Object ....... : AR.AR_PAYMENT_SCHEDULES_ALL
Message ......... : Index Fast Full Scan:  AR.AR_PAYMENT_SCHEDULES_ALL: 58776 out of 73853 Blocks done
----------------------------------------------------------
START TIME ...... : 08-FEB-2016 15:01:08
Elapsed in min .... : 69:35
Remaining ......... : 39:24
Complete_pct .... : 63.51

SQL ID .......... : f8h3xq0c5sqb6
SQL hash value .. : 408705382
db Object ....... : AR.AR_CASH_RECEIPTS_ALL
Message ......... : Table Scan:  AR.AR_CASH_RECEIPTS_ALL: 528906 out of 832791 Blocks done

  • Script finds database session info by entering a concurrent Request ID:
When the concurrent Request is still in Running status and if column ORACLE_SESSION_ID in table fnd_concurrent_requests is populated, below query shall return accurate information. Seem to me when the concurrent Request is near to finish, sometimes that column could get erased to NULL.
X~~~~~~~~~~~~~~~~~~~~~ enter EBS Request ID ~~~~~~~~~~~~~~~~~~~~~X
set echo off
set linesize 150
set verify off
set feedback off
set serveroutput on size 1000000

DECLARE
cursor sess_cursor is
select
        p.spid,
        s.process,
        s.sid,
        s.serial#,
        s.username,
        s.status,
        s.machine,
        s.terminal,
        s.program,
        s.module,
        s.action,
        s.sql_hash_value,
        s.sql_address,
        to_char(s.logon_time, 'DD-Mon-YYYY HH24:MI:SS') logontime,
        round((s.last_call_et/60),2) last_call_et,
        s.seconds_in_wait,
        s.client_identifier,
        s.sql_id,
        w.event,
        w.state
from
        v$session s, v$process p, v$session_wait w, fnd_concurrent_requests f
where
           s.paddr = p.addr
and     s.sid = w.sid
and     f.ORACLE_SESSION_ID = s.AUDSID
and     f.request_id='&Request_id';

begin
dbms_output.put_line('------------------------------------------------------------------------------');
dbms_output.put_line(' CM Request: database session details associated with Request id ');
dbms_output.put_line('------------------------------------------------------------------------------');

for x in sess_cursor
loop
        dbms_output.put_line('DB PID ......... : ' || x.spid);
        dbms_output.put_line('EBS PID ........ : ' || x.process);
        dbms_output.put_line('SID ............ : ' || x.sid);
        dbms_output.put_line('Serial# ........ : ' || x.serial#);
        dbms_output.put_line('Username ....... : ' || x.username);
        dbms_output.put_line('Status ......... : ' || x.status);
        dbms_output.put_line('Machine ........ : ' || x.machine);
        dbms_output.put_line('Terminal ....... : ' || x.terminal);
        dbms_output.put_line('Program ........ : ' || x.program);
        dbms_output.put_line('Module ......... : ' || x.module);
        dbms_output.put_line('Action ......... : ' || x.action);
        dbms_output.put_line('SQL Hash Value . : ' || x.sql_hash_value);
        dbms_output.put_line('Logon Time ..... : ' || x.logontime);
        dbms_output.put_line('Last Call Et ... : ' || x.last_call_et || ' ' || 'min');
        dbms_output.put_line('Seconds in Wait. : ' || x.seconds_in_wait);
        dbms_output.put_line('User ID ........ : ' || x.client_identifier);
        dbms_output.put_line('Session State .. : ' || x.state);
        dbms_output.put_line('Wait Event ..... : ' || x.event);
        dbms_output.put_line('SQL ID ... ..... : ' || x.sql_id);
        dbms_output.put_line('SQL Text ....... : ');

        for y in (
                select sql_text
                from v$sqltext v
                where
                v.hash_value = x.sql_hash_value
                and v.address = x.sql_address
                order by v.piece)
        loop
                dbms_output.put_line(' ' || y.sql_text);
        end loop;
        dbms_output.put_line('Progress in DB (SID: '|| x.sid ||')');
        for z in (
               SELECT
               ROUND(sl.elapsed_seconds/60) || ':' || MOD(sl.elapsed_seconds,60) elapsed,
               ROUND(sl.time_remaining/60) || ':' || MOD(sl.time_remaining,60) remaining,
               ROUND(sl.sofar/sl.totalwork*100, 2) progress_pct,
               sl.sql_id, sl.message, sl.sql_hash_value,
               opname operation,
               target object,
               to_char(start_time, 'DD-MON-YYYY HH24:MI:SS') start_time
               FROM   v$session_longops sl
               WHERE  sl.sid = x.sid AND sl.serial# = x.serial#
                      AND totalwork > 0
              order by progress_pct desc, start_time asc)
        loop
                 dbms_output.put_line('----------------------------------------------------------');
                 dbms_output.put_line('  START TIME ...... : ' || z.start_time);
                 dbms_output.put_line('  Elapsed in min .. : ' || z.elapsed);
                 dbms_output.put_line('  Remaining ....... : ' || z.remaining);
                 dbms_output.put_line('  Complete_pct .... : ' || z.progress_pct);
                 dbms_output.put_line('  SQL ID .......... : ' || z.sql_id);
                 dbms_output.put_line('  SQL hash value .. : ' || z.sql_hash_value);
                 dbms_output.put_line('  db Object ....... : ' || z.object);
                 dbms_output.put_line('  Message ......... : ' || z.message);
       end loop;

  dbms_output.put_line('--------------------------------------------------------------------');
end loop;
end;
/
  • Script finds database session info by entering OS process ID on Apps node 
X~~~~~~~~~~~~~~~~~~~~~ enter OS process ID ~~~~~~~~~~~~~~~~~~~~~~~X
set echo off
set linesize 150
set verify off
set feedback off
set serveroutput on size 1000000
DECLARE
v_sql_id  v$sql.sql_id%type;
cursor sess_cursor is
select
        p.spid,
        s.process,
        s.sid,
        s.serial#,
        s.username,
        s.status,
        s.machine,
        s.terminal,
        s.program,
        s.module,
        s.action,
        s.sql_hash_value,
        s.sql_address,
        to_char(s.logon_time, 'DD-Mon-YYYY HH24:MI:SS') logontime,
        round((s.last_call_et/60),2) last_call_et,
        s.seconds_in_wait,
        s.client_identifier,
        s.sql_id,
        w.event,
        w.state
from
        v$session s, v$process p, v$session_wait w
where
           s.paddr = p.addr
and     s.sid = w.sid
and     s.process = '&EBS_OS_pid';

begin
dbms_output.put_line('------------------------------------------------------------------------------');
dbms_output.put_line(' Database session details associated with Process id ');
dbms_output.put_line('------------------------------------------------------------------------------');

for x in sess_cursor
loop
        -- select distinct sql_id into v_sql_id from v$sqltext v
        --  where v.hash_value = x.sql_hash_value
        --   and v.address = x.sql_address;
        dbms_output.put_line('DB PID ......... : ' || x.spid);
        dbms_output.put_line('EBS PID ........ : ' || x.process);
        dbms_output.put_line('SID ............ : ' || x.sid);
        dbms_output.put_line('Serial# ........ : ' || x.serial#);
        dbms_output.put_line('Username ....... : ' || x.username);
        dbms_output.put_line('Status ......... : ' || x.status);
        dbms_output.put_line('Machine ........ : ' || x.machine);
        dbms_output.put_line('Terminal ....... : ' || x.terminal);
        dbms_output.put_line('Program ........ : ' || x.program);
        dbms_output.put_line('Module ......... : ' || x.module);
        dbms_output.put_line('Action ......... : ' || x.action);
        dbms_output.put_line('SQL Hash Value . : ' || x.sql_hash_value);
        dbms_output.put_line('Logon Time ..... : ' || x.logontime);
        dbms_output.put_line('Last Call Et ... : ' || x.last_call_et || ' ' || 'min');
        dbms_output.put_line('Seconds in Wait. : ' || x.seconds_in_wait);
        dbms_output.put_line('User ID ........ : ' || x.client_identifier);
        dbms_output.put_line('Session State .. : ' || x.state);
        dbms_output.put_line('Wait Event ..... : ' || x.event);
        dbms_output.put_line('SQL ID ... ..... : ' || x.sql_id);
        dbms_output.put_line('SQL Text ....... : ');

        for y in (
                select sql_text
                from v$sqltext v
                where
                v.hash_value = x.sql_hash_value
                and v.address = x.sql_address
                order by v.piece)
        loop
                dbms_output.put_line(' ' || y.sql_text);
        end loop;
        dbms_output.put_line('Progress in DB (SID: '|| x.sid ||')');
        for z in (
               SELECT
               ROUND(sl.elapsed_seconds/60) || ':' || MOD(sl.elapsed_seconds,60) elapsed,
               ROUND(sl.time_remaining/60) || ':' || MOD(sl.time_remaining,60) remaining,
               ROUND(sl.sofar/sl.totalwork*100, 2) progress_pct,
               sl.sql_id, sl.message, sl.sql_hash_value,
               opname operation,
               target object,
               to_char(start_time, 'DD-MON-YYYY HH24:MI:SS') start_time
               FROM   v$session_longops sl
               WHERE  sl.sid = x.sid AND sl.serial# = x.serial#
                      AND totalwork > 0
              order by progress_pct desc, start_time asc)
        loop
                 dbms_output.put_line('----------------------------------------------------------');
                 dbms_output.put_line('  START TIME ...... : ' || z.start_time);
                 dbms_output.put_line('  Elapsed in min .. : ' || z.elapsed);
                 dbms_output.put_line('  Remaining ....... : ' || z.remaining);
                 dbms_output.put_line('  Complete_pct .... : ' || z.progress_pct);
                 dbms_output.put_line('  SQL ID .......... : ' || z.sql_id);
                 dbms_output.put_line('  SQL hash value .. : ' || z.sql_hash_value);
                 dbms_output.put_line('  db Object ....... : ' || z.object);
                 dbms_output.put_line('  Message ......... : ' || z.message);
       end loop;
  dbms_output.put_line('--------------------------------------------------------------------');
end loop;
end;
/