Wednesday, July 6, 2011

workflow notification mailer is consuming 100%CPU performance degradation till loss of service javax.mail.MessagingException: 451 Timeout waiting for client input

Visit the Below Website to access unlimited exam questions for all IT vendors and Get Oracle Certifications for FREE
http://www.free-online-exams.com

Problem:    workflow notification mailer is consuming 100%CPU performance degradation till loss of service javax.mail.MessagingException: 451 Timeout waiting for client input
Workflow Mailer java process is consuming 100% of CPU on Apps server which degrades the performance and bounce is needed.
javax.mail.MessagingException: 451 Timeout waiting for client input

Log files:
wf_output.log

Filename = <a href="http://sew.oraclecorp.com/SEW/fileDownload?forceDownload=0&fileURL=https%3A%2F%2Fgtcr.oracle.com%2Fgtcr-dir%2Fgtcr_546379931%2F7583240.992%2Fwf_output.zip"target="_blank">https://gtcr.oracle.com/gtcr-dir/gtcr_546379931/7583240.992/wf_output.zip</a>

MT+04:00]:1241533971006:Thread[outboundThreadGroup1,5,outboundThreadGroup]:0:-1:Servername:IPAddress:-1:-1:ERROR:[SVC-GSM-WFMLRSVC-73035-10006 : oracle.apps.fnd.wf.mailer.SMTPOutboundProcessor.send(Message)]:Problem encountered when sending to {[["USERNAME" <Email>]]} -> javax.mail.MessagingException: 451 Timeout waiting for client input

[May 5, 2009 6:32:51 PM GMT+04:00]:1241533971007:Thread[outboundThreadGroup1,5,outboundThreadGroup]:0:-1:Servername:IPAddress:-1:-1:ERROR:[SVC-GSM-WFMLRSVC-73035-10006 : oracle.apps.fnd.wf.mailer.SMTPMessageHandler.sendMessages(String)]:MessagingException -> javax.mail.MessagingException: 451 Timeout waiting for client input

[May 5, 2009 6:33:28 PM GMT+04:00]:1241534008921:Thread[inboundThreadGroup1,5,inboundThreadGroup]:0:-1:Servername:IPAddress:-1:-1:ERROR:[SVC-GSM-WFMLRSVC-73035-10006 : oracle.apps.fnd.wf.mailer.IMAPInboundProcessor.readNewMessages()]:Connection to the INBOX has been lost

[May 14, 2009 12:54:27 AM GMT+04:00]:1242248067600:Thread[outboundThreadGroup1,5,outboundThreadGroup]:0:-1:Servername:IPAddress:-1:-1:ERROR:[SVC-GSM-WFMLRSVC-73490-10006 : oracle.apps.fnd.wf.mailer.SMTPMessageHandler.sendMessages(String)]:Not sending notification 20985431 because could not locate the row in the notification table
[May 14, 2009 12:54:32 AM GMT+04:00]:1242248072987:Thread[outboundThreadGroup1,5,outboundThreadGroup]:0:-1:Servername:IPAddress:-1:-1:UNEXPECTED:[fnd.wf.mailer.URLMIMETagListener]:oracle.apps.fnd.wf.mailer.URLMIMETagListener.editStyleRef(HTMLTagEvent, String) Making a connection to {http://sid.dubaiworld.ae:80/OA_HTML/cabo/images/cache/cmbts.gif)} returned {404 - Not Found}. Leaving as a reference
[May 14, 2009 2:25:01 AM GMT+04:00]:1242253501108:Thread[inboundThreadGroup1,5,inboundThreadGroup]:0:-1:Servername:IPAddress:-1:-1:ERROR:[SVC-GSM-WFMLRSVC-73490-10006 : oracle.apps.fnd.wf.mailer.IMAPInboundProcessor.moveMessage(Message, String)]:Source folder {INBOX} is not open.
[May 14, 2009 2:25:24 AM GMT+04:00]:1242253524409:Thread[outboundThreadGroup1,5,outboundThreadGroup]:0:-1:Servername:IPAddress:-1:-1:ERROR:[SVC-GSM-WFMLRSVC-73490-10006 : oracle.apps.fnd.wf.mailer.SMTPOutboundProcessor.send(Message)]:Problem encountered when sending to {[["ABDULLA, KHALID ABDULREDHA ABDULLA" <Khaled.AbdulRedha@jafza.ae>]]} -> javax.mail.MessagingException: 451 Timeout waiting for client input

[May 8, 2009 10:10:47 PM GMT+04:00]:1241806247678:Thread[Thread-0,1,main]:0:-1:Servername:IPAddress:-1:-1:ERROR:[fnd.common.ErrorStack]:java.sql.SQLException: ORA-01033: ORACLE initialization or shutdown in progress

at oracle.jdbc.dbaccess.DBError.throwSqlException(DBError.java:134)
at oracle.jdbc.ttc7.TTIoer.processError(TTIoer.java:289)
at oracle.jdbc.ttc7.O3log.receive1st(O3log.java:410)
at oracle.jdbc.ttc7.TTC7Protocol.logon(TTC7Protocol.java:260)
at oracle.jdbc.driver.OracleConnection.<init>(OracleConnection.java:371)
at oracle.jdbc.driver.OracleDriver.getConnectionInstance(OracleDriver.java:551)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:351)
at java.sql.DriverManager.getConnection(DriverManager.java:512)
at java.sql.DriverManager.getConnection(DriverManager.java:140)
at oracle.apps.fnd.security.ConnectionManager.dbConnect(ConnectionManager.java:1194)
at oracle.apps.fnd.security.AppsConnectionManager.localAppsConnect(AppsConnectionManager.java:976)
at oracle.apps.fnd.security.AppsConnectionManager.localAppsConnect(AppsConnectionManager.java:868)
at oracle.apps.fnd.security.AppsConnectionManager.localAppsConnect(AppsConnectionManager.java:857)
at oracle.apps.fnd.security.AppsConnectionManager.makeGuestConnection(AppsConnectionManager.java:586)
at oracle.apps.fnd.security.DBConnObj.<init>(DBConnObj.java:246)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:274)
at oracle.apps.fnd.common.Pool.createObject(Pool.java:1287)
at oracle.apps.fnd.common.Pool.createAvailableObject(Pool.java:2225)
at oracle.apps.fnd.common.Pool.resize(Pool.java:2103)
at oracle.apps.fnd.common.Pool.run(Pool.java:1985)
at java.lang.Thread.run(Thread.java:534)

[May 8, 2009 10:10:47 PM GMT+04:00]:1241806247678:Thread[Thread-0,1,main]:0:-1:Servername:IPAddress:-1:-1:ERROR:[fnd.common.ErrorStack]:SECURITY_APPL_LOGIN_FAILED

alert.log

Completed: ALTER DATABASE BACKUP CONTROLFILE TO '/backup1/sidbak/onln_bkp/ctrlSID2.ctl.162.1304'
Wed May 13 23:59:10 2009
Some indexes or index [sub]partitions of table HR.PER_EMPDIR_PEOPLE have been marked unusable
Thu May 14 00:03:47 2009
Some indexes or index [sub]partitions of table HR.PER_EMPDIR_ASSIGNMENTS have been marked unusable
Thu May 14 00:03:52 2009
Some indexes or index [sub]partitions of table HR.PER_EMPDIR_ORGANIZATIONS have been marked unusable
Thu May 14 00:03:56 2009
Some indexes or index [sub]partitions of table HR.PER_EMPDIR_PHONES have been marked unusable
Thu May 14 00:04:27 2009
Some indexes or index [sub]partitions of table HR.PER_EMPDIR_POSITIONS have been marked unusable
Thu May 14 00:04:28 2009
Thread 2 advanced to log sequence 69442
Current log# 8 seq# 69442 mem# 0: /u02/sid/siddata/log08.dbf
Thu May 14 00:04:30 2009
Some indexes or index [sub]partitions of table HR.PER_EMPDIR_JOBS have been marked unusable
Thu May 14 00:04:32 2009
Some indexes or index [sub]partitions of table HR.PER_EMPDIR_LOCATIONS have been marked unusable
Thu May 14 00:04:36 2009
Some indexes or index [sub]partitions of table HR.PER_EMPDIR_LOCATIONS_TL have been marked unusable
Thu May 14 01:30:23 2009
Thread 2 advanced to log sequence 69443
Current log# 10 seq# 69443 mem# 0: /u02/sid/siddata/log10.dbf
Thu May 14 01:34:32 2009
Thread 2 advanced to log sequence 69444
Current log# 9 seq# 69444 mem# 0: /u02/sid/siddata/log09.dbf
Thu May 14 02:25:00 2009
ORA-01555 caused by SQL statement below (SQL ID: dsphq1qsnymv8, Query Duration=1242253500 sec, SCN: 0x010e.b4f05697):
Thu May 14 02:25:00 2009
BEGIN WF_EVENT_OJMSTEXT_QH.DEQUEUE(:1, :2, :3); END;

Solution:
You are experiencing Bug.6511028 - WORKFLOW SERVICE CONTAINER CONSUMING A LOT OF TEMPORARY SEGEMENTS
The patch for your version which is 11.5.10 + ATG RUP4 is patch# 6940918

Other work around might help as below:
-          Caused by the failure of Mailer in processing the notifications
-          Run Ready messages in WF_DEFERRED queue manually
-          reduce the chatting between the SMTP server and java mailer by going to OAM, Mailer Configuration, Step 2 - check the box for Processor Close on Read Timeout

- Run the workflow deferred agent listener from sqlplus in order to process all the events
a. Source APPSORA.env so you can run sqlplus from any location and use the $FND_TOP env variable:

. APPSORA.env

b. Login to sqlplus as the apps user:

sqlplus apps/apps

c. Make a script of the following and run it logged in as apps. It will create a file called
debug.log showing what it is doing as it dequeues. Failing events will also be enqueued on the
WF_ERROR queue:

================Begin Script========================

@$FND_TOP/patch/115/sql/wfdbginit.sql 1 %
spool debug.log;
exec wf_log_pkg.wf_debug_flag := true;
exec fnd_log.g_current_runtime_level := 1;

begin

wf_event.listen(p_agent_name => 'WF_DEFERRED');
end;
/
col module format a15 ;
col message_text format a40;

commit;
@$FND_TOP/patch/115/sql/wfdbgprnt.sql wf.plsql.%

select fnd_debug_util.get_trace_file_name() tracefile from dual;

spool off;

================End Script===========================

Note: This script will take time because there are several events in the WF_DEFERRED queue.

B. Rebuild and clean.

a. Shutdown the Workflow Mailer Service and Workflow Agent Listener Service then run the following:

sqlplus apps/apps @$FND_TOP/sql/wfevqcln.sql WF_DEFERRED oracle.apps.wf.notification.%

OR based on your patch level

sqlplus apps/apps @$FND_TOP/sql/wfevqcln.sql WF_DEFERRED oracle.apps.wf.notification.% 0 (CU 2 and above)

b. Conditionally required for ATG RUP4 and above Oracle Alert users:

NOTE: APPLSYS is assumed to be the schema storing the Workflow tables. Please substitute the correct schema name if necessary.

1. Backup the Oracle Alert messages that are unprocessed on the WF_NOTIFICATION_OUT.

ASSUMPTION: The corrupt messages are not belonging to Oracle Alert.

create table APPLSYS.AQ$WF_NOTIFICATION_OUT_BAK as select * from APPLSYS.AQ$WF_NOTIFICATION_OUT where CORR_ID like
'APPS:ALR%' and msg_state in ('READY','WAIT');

2. Confirm that all Oracle Alert messages have been backup:

set linesize 155;
set pagesize 200;
set verify off;
SELECT COUNT(*),
substr(corr_id,1,45) corr_id,
msg_state
FROM applsys.aq$wf_notification_out
WHERE corr_id LIKE 'APPS:ALR%'
AND msg_state IN('READY', 'WAIT')
GROUP BY corr_id,
msg_state;

Compare:

set linesize 155;
set pagesize 200;
set verify off;
SELECT COUNT(*),
substr(corr_id,1,45) corr_id,
msg_state
FROM applsys.aq$wf_notification_out_bak
WHERE corr_id LIKE 'APPS:ALR%'
AND msg_state IN('READY', 'WAIT')
GROUP BY corr_id,
msg_state;


3. Drop the WF_NOTIFICATION_OUT queue to remove all the other messages:

sqlplus apps/apps

Exec dbms_aqadm.stop_queue( queue_name => 'APPLSYS.WF_NOTIFICATION_OUT', wait => FALSE);

exec dbms_aqadm.drop_queue_table( queue_table => 'APPLSYS.WF_NOTIFICATION_OUT', force => TRUE);

4. Recreate WF_NOTIFICATION_OUT as it need to exist for $FND_TOP/patch/115/sql/wfntfqup.sql to run successfully. See the steps :

i. Run the following to recreate the JMS queues:

sqlplus APPSusr/APPSpwd @wfjmsqc2.sql FNDusr FNDpwd

Example:

sqlplus apps/apps @$FND_TOP/patch/115/sql/wfjmsqc2.sql applsys apps


ii. Add the subscribers:

sqlplus APPSusr/APPSpwd @wfmqsubc2.sql FNDusr FNDpwd

Example Syntax:

sqlplus apps/apps @$FND_TOP/patch/115/sql/wfmqsubc2.sql APPLSYS APPS

c. Required by ALL: Now run to repopulate the WF_NOTIFICATION_OUT queue:

sqlplus usr/passwd@db @$FND_TOP/patch/115/sql/wfntfqup APPSusr APPSpw FNDusr

Example Syntax:

sqlplus apps/apps @$FND_TOP/patch/115/sql/wfntfqup APPS apps APPLSYS


5. Required for Oracle Alert: Make the following into a script and run it from the apps schema. It will ONLY put Oracle Alert messages that are unprocessed on the WF_NOTIFICATION_OUT queue.


===============Begin Script=============================

set serveroutput on size 100000;
declare
x_out_queue varchar2(80) := 'APPLSYS.WF_NOTIFICATION_OUT';
x_enqueue_options dbms_aq.enqueue_options_t;
x_message_properties dbms_aq.message_properties_t;
x_msgid RAW(16);
i number := 0;
p_event SYS.AQ$_JMS_TEXT_MESSAGE;

cursor msg is
select * from APPLSYS.AQ$WF_NOTIFICATION_OUT_BAK
where msg_state in ('READY','WAIT');

begin

for m1 in msg loop

x_out_queue := 'APPLSYS.'||m1.queue;
x_message_properties.correlation := m1.corr_id;
--x_message_properties.original_msgid := m1.msg_id;
x_message_properties.priority := m1.msg_priority;

x_message_properties.recipient_list(1) := sys.aq$_agent(m1.consumer_name,
null,
0);
if (m1.msg_state = 'WAIT') and (m1.delay > sysdate) then
x_message_properties.delay := ((sysdate - m1.delay)*86400);
else
x_message_properties.delay := 0;
end if;
--dbms_output.put_line('msg.msgid = ' || m1.msg_id);

DBMS_AQ.ENQUEUE(
queue_name => x_out_queue,
enqueue_options => x_enqueue_options,
message_properties => x_message_properties,
payload => m1.user_data,
msgid => x_msgid); /* OUT*/

--dbms_output.put_line('x_msgid = ' || x_msgid);

if i = 20 then
i := 0;
commit;
else
i := i + 1;
end if;
end loop;

commit;
exception
when others then
dbms_output.put_line('sqlerrm = ' || sqlerrm);
end;
/

=========End Script======================================


6. Confirm that all Oracle Alert messages are back on the wf_notification_out queue:

set linesize 155;
set pagesize 200;
set verify off;
SELECT COUNT(*),
substr(corr_id,1,45) corr_id,
msg_state
FROM applsys.aq$wf_notification_out
WHERE corr_id LIKE 'APPS:ALR%'
AND msg_state IN('READY', 'WAIT')
GROUP BY corr_id,
msg_state;

d. Create Index on WF Queue Tables

NOTE: The index tablespace can be determined by running the following select. Please ignore any ora-0955 errors as the only missing index is WF_NOTIFICATION_OUT_N1. Use the same tablespace_name as the one that belongs to WF_NOTIFICATION_IN_N1:

select tablespace_name, index_name from dba_indexes where index_name like 'WF_%_N1';

sqlplus usr/passwd@db @$FND_TOP/patch/115/sql/wfqidxc FNDusr FNDpwd tablespace_name

OR based on your patch level

sqlplus usr/passwd@db @$FND_TOP/patch/115/sql/wfqidxc2 FNDusr FNDpwd tablespace_name

Example Syntax:

sqlplus apps/apps @$FND_TOP/patch/115/sql/wfqidxc APPLSYS APPS USER_IDX

sqlplus apps/apps @$FND_TOP/patch/115/sql/wfqidxc2 APPLSYS APPS APPS_TS_QUEUES

e. Work Flow Histograms Creation Script.

sqlplus usr/passwd@db @$FND_TOP/patch/115/sql/wfhistc FNDusr

Example Syntax:

sqlplus apps/apps @$FND_TOP/patch/115/sql/wfhistc APPLSYS

f. Then restart the Workflow Mailer Service and Workflow Agent Listener Service.


References:
Note.567762.1 Gen EVENTS.P-1151 Ext/Pub Performance Issues with Workflow Service Container
Bug 6511028 - WORKFLOW SERVICE CONTAINER CONSUMING A LOT OF TEMPORARY SEGEMENTS
Bug 6940918 1OFF:11IRU4:6511028 : WORKFLOW CONTAINERS CONSUMING LOT OF TEMP TABLE SPACE


    
Get Oracle Certifications for all Exams
Free Online Exams.com

No comments: