Clarity Upgrade 15.4 -Portlet Performance Issue

[Ritesh Pandey]

Hi All ,

We are facing one weird  performance issue while accessing one custom portlet after upgrade to 15.4.

The portlet takes quite a long time to open up for the first time ( more than 20 mins ) however comes up very quick (less than in a minute ) in the subsequent run . To analyse it ,  we have taken up the app trace for this issue , can see 2 times the <nsq_internal> tag is being called in the <portletRequest id > tag with the same query id (myquery_id:5045029)

 

The first call shows almost 20 mins to execute it and the same <nsq_internal > tag  is just taking 4 secs to execute it .

My 3 questions -

1. Why this <persistence id="nsql_internal> tag is being called twice , is this the correct behavior?

2.  In the first <persistence id="nsql_internal> tag , why the associated query is not being shown  while I can see my portlet query in the second <persistence id="nsql_internal > tag . Is the first call without SQL query is the reason for slowness regarding the  performance issue in the first time execution .

3. Any idea why the first <nsql_internal> takes 20 mins to complete it .

 

Please advice if anyone has faced such issue earlier .

 

 <portletRequest id="myportlet_id" 

 <persistence id="nsql_internal" elapsed="1,186,224.000" elapsedSincePriorNode="54.000"          elapsedAfterLastNode="0.000" start="4:48:45:578" finish="5:08:31:802" memoryDelta="756095k">
<statementSet id="nsql_internal" elapsedSincePriorNode="0.000" start="4:48:45:578"/>
<statement id="myquery_id:5045029" elapsed="1,186,221.000" elapsedSincePriorNode="1,534,322,925,582.000" start="4:48:45:581" finish="5:08:31:802" memoryDelta="755836k"/>

</persistence>

 

<persistence id="nsql_internal" elapsed="3,995.000" elapsedSincePriorNode="2.000" elapsedAfterLastNode="0.000" start="5:08:32:251" finish="5:08:36:246" memoryDelta="21648k">
<statementSet id="nsql_internal" elapsedSincePriorNode="0.000" start="5:08:32:251"/>
<statement id="myquery_id:5045029" elapsed="3,993.000" elapsedSincePriorNode="1,534,324,112,254.000" elapsedAfterLastNode="30.000" start="5:08:32:253" finish="5:08:36:246" memoryDelta="21648k">
<execute id="STMT@7bf7c54c" elapsed="0.000" elapsedSincePriorNode="1.000" start="5:08:32:254" finish="5:08:32:254" memoryDelta="0k">
</execute>
<execute id="STMT@6a6a04fd" elapsed="3,858.000" elapsedSincePriorNode="104.000" start="5:08:32:358" finish="5:08:36:216" memoryDelta="3919k">
</execute>
</statement>
</persistence>

</persistence>

[Ritesh Pandey]

Hi All once again , in the continuation of the aforesaid issue - when I executed the trace for the second time ,  I can seethe first <persistence id="nsql_internal"> tag is just showing 64 Millie Sec to get completed in compare to earlier 20 mins in the first run .

 

<persistence id="nsql_internal" elapsed="64.000" elapsedSincePriorNode="37.000" elapsedAfterLastNode="0.000" start="8:11:28:016" finish="8:11:28:080" memoryDelta="4700k">
<statementSet id="nsql_internal" elapsedSincePriorNode="0.000" start="8:11:28:016"/>
<statement id="myquery_id:5045029" elapsed="62.000" elapsedSincePriorNode="1,534,335,088,019.000" start="8:11:28:018" finish="8:11:28:080" memoryDelta="4534k"/>
</persistence>

[David Morton]

What happens when you run the portlet's SQL on its own against the database?

 

( you can get situations where the first run of a SQL statement takes a lot longer than subsequent runs because the query-execution-plan is complex and has been cached in subsequent runs and/or the actual data is being cached for the subsequent runs. Although "20 minutes" sounds a LOT more than I would imagine in this situation)

 

So what I'm getting at is, if the first run of the SQL alone takes a very long time, then you have a database/SQL issue (potentially fixed by your DBA and adding hints to the SQL statement, or even rewriting it) - but if the SQL always runs super-quick on its own and just the initial-portlet-execution is misbehaving... I think I'd be raising a case with support to help me.

[Ritesh Pandey]

Thanks David ! We have got the session monitored from DBA and the query is getting executed in less than 1 minute . 

Apparently this portlet performance issue happens when this portlet is being accessed for the first time by the user. 

[David Morton]

Yeah so that does NOT sound like the problem is SQL-based, so its unlikely that there is a simple answer

 

I'd be tempted to try various things like;

• running the portlet with different users (do they ALL get the same problem?, if the problem is restricted to a specific user then examine their access rights etc)
• XOG-ing out the portlet / deleting the portlet / reloading it - does the problem persist?
• rebuilding the query and the portlet from scratch (with different IDs) - does the problem happen in the "new" portlet?

 

and then give up and contact support. 

[Suman Pramanik]

HI Ritesh

 

The persistence is called to fetch the data from cache. Please log a case and we will have a detailed look.

 

Regards
Suman Pramanik 

[Ritesh Pandey]

Thanks Suman . Already raised a case #01154908 

[Suman Pramanik]

Thanks Ritesh I have already discussed this with the team and will come back to you.