Page Display slowness

[Walter Vaughan]

We have noticed a drastic slowness in building pages that does not seem to be
fixed with following the Production Guide instructions on setting the caches.

I realize we have a ton more to learn, but I need to start doing demonstrations
of our Data in OFBiz, and I need it to work within expectations.

We are seeing sometimes as long as 29 seconds to finish drawing a page.

We are "svn"ed as of yesterday.

For example, clicking on the Catalog draws the left hand side instantly, but
hangs for 10 to 20 seconds sometimes before it displays the "catalog
adminstration main page screenlet".

Another example is clicking on Party. I draws the top half instantly, and takes
as long as 10 to 30 seconds to display the "parties found" screenlet.

I've included a log that probably isn't interesting till later in the dump

2006-08-18 14:23:20,017 (TP-Processor8) [     ControlServlet.java:90 :INFO ] The
character encoding of the request is: [null]. The character encoding we will use
for the request and response is: [UTF-8]
2006-08-18 14:23:20,018 (TP-Processor8) [     ControlServlet.java:126:DEBUG]
[[[main] Servlet Starting, doing setup- total:0.0,since last(Begin):0.0]]
2006-08-18 14:23:20,019 (TP-Processor8) [     ControlServlet.java:175:DEBUG]
[[[main] Setup done, doing Event(s) and View(s)- total:0.0,since last([main]
Servlet St...):0.0]]
2006-08-18 14:23:20,020 (TP-Processor8) [     RequestHandler.java:203:INFO ]
[Processing Request]: main
2006-08-18 14:23:20,024 (TP-Processor8) [     RequestManager.java:114:INFO ]
[RequestManager.getRequestAttribute] Value for attribute "null" of uri "main"
not found
2006-08-18 14:23:20,025 (TP-Processor8) [     RequestHandler.java:386:INFO ]
[RequestHandler.doRequest]: Response is a view.
2006-08-18 14:23:20,026 (TP-Processor8) [     RequestHandler.java:538:INFO ]
servletName=control, view=main
2006-08-18 14:23:20,027 (TP-Processor8) [     ScreenRenderer.java:194:INFO ]
Found session attribute that conflicts with parameter name, leaving request
parameter in place for name: externalLoginKey
2006-08-18 14:23:20,028 (TP-Processor8) [   PrimaryKeyFinder.java:132:INFO ]
Returning null because found incomplete primary key in find:
[GenericEntity:Product][productId,null()]
2006-08-18 14:23:20,352 (TP-Processor8) [  ServiceDispatcher.java:450:DEBUG]
[[Sync service finished- total:0.0010,since last(Begin):0.0010]] - 'catalog /
getProductCategoryAndLimitedMembers'
2006-08-18 14:23:43,452 (TP-Processor8) [     ControlServlet.java:250:DEBUG]
[[[main] Done rendering page, Servlet Finished- total:23.433,since last([main]
Setup done...):23.433]]
2006-08-18 14:23:47,701 (TP-Processor3) [     ControlServlet.java:90 :INFO ] The
character encoding of the request is: [null]. The character encoding we will use
for the request and response is: [UTF-8]
2006-08-18 14:23:47,702 (TP-Processor3) [     ControlServlet.java:126:DEBUG]
[[[main] Servlet Starting, doing setup- total:0.0,since last(Begin):0.0]]
2006-08-18 14:23:47,703 (TP-Processor3) [     ControlServlet.java:175:DEBUG]
[[[main] Setup done, doing Event(s) and View(s)- total:0.0,since last([main]
Servlet St...):0.0]]
2006-08-18 14:23:47,704 (TP-Processor3) [     RequestHandler.java:203:INFO ]
[Processing Request]: main
2006-08-18 14:23:47,705 (TP-Processor3) [     RequestManager.java:114:INFO ]
[RequestManager.getRequestAttribute] Value for attribute "null" of uri "main"
not found
2006-08-18 14:23:47,706 (TP-Processor3) [     RequestHandler.java:386:INFO ]
[RequestHandler.doRequest]: Response is a view.
2006-08-18 14:23:47,706 (TP-Processor3) [     RequestHandler.java:538:INFO ]
servletName=control, view=main
2006-08-18 14:23:47,707 (TP-Processor3) [     ScreenRenderer.java:194:INFO ]
Found session attribute that conflicts with parameter name, leaving request
parameter in place for name: externalLoginKey
2006-08-18 14:23:47,722 (TP-Processor3) [  ServiceDispatcher.java:450:DEBUG]
[[Sync service finished- total:0.013,since last(Begin):0.013]] - 'partymgr /
findParty'
2006-08-18 14:23:47,769 (TP-Processor3) [  ModelScreenWidget.java:362:INFO ] In
the include-screen tag the screen name was empty, ignoring include; in screen
[GlobalDecorator]
2006-08-18 14:23:53,976 (TP-Processor3) [     ControlServlet.java:250:DEBUG]
[[[main] Done rendering page, Servlet Finished- total:6.272,since last([main]
Setup done...):6.272]]
2006-08-18 14:24:41,021 (TP-Processor2) [     ControlServlet.java:90 :INFO ] The
character encoding of the request is: [null]. The character encoding we will use
for the request and response is: [UTF-8]
2006-08-18 14:24:41,022 (TP-Processor2) [     ControlServlet.java:126:DEBUG]
[[[main] Servlet Starting, doing setup- total:0.0,since last(Begin):0.0]]
2006-08-18 14:24:41,023 (TP-Processor2) [     ControlServlet.java:175:DEBUG]
[[[main] Setup done, doing Event(s) and View(s)- total:0.0,since last([main]
Servlet St...):0.0]]
2006-08-18 14:24:41,024 (TP-Processor2) [     RequestHandler.java:203:INFO ]
[Processing Request]: main
2006-08-18 14:24:41,025 (TP-Processor2) [     RequestManager.java:114:INFO ]
[RequestManager.getRequestAttribute] Value for attribute "null" of uri "main"
not found
2006-08-18 14:24:41,026 (TP-Processor2) [     RequestHandler.java:386:INFO ]
[RequestHandler.doRequest]: Response is a view.
2006-08-18 14:24:41,027 (TP-Processor2) [     RequestHandler.java:538:INFO ]
servletName=control, view=main
2006-08-18 14:24:41,028 (TP-Processor2) [     ScreenRenderer.java:194:INFO ]
Found session attribute that conflicts with parameter name, leaving request
parameter in place for name: externalLoginKey
2006-08-18 14:24:41,029 (TP-Processor2) [   PrimaryKeyFinder.java:132:INFO ]
Returning null because found incomplete primary key in find:
[GenericEntity:Product][productId,null()]
2006-08-18 14:24:41,252 (TP-Processor2) [  ServiceDispatcher.java:450:DEBUG]
[[Sync service finished- total:0.0010,since last(Begin):0.0010]] - 'catalog /
getProductCategoryAndLimitedMembers'
2006-08-18 14:24:42,732 (TP-Processor2) [     ControlServlet.java:250:DEBUG]
[[[main] Done rendering page, Servlet Finished- total:1.708,since last([main]
Setup done...):1.708]]

[David E Jones-2]

There are a LOT of things that affect performance. Your best bet is  
to have someone with experience take a look at it.

At a high level there are a few things to watch out for that seem to  
come up often:

1. cache settings and performance statistics

2. server resources, especially memory and looking at paging to/from  
the hard to see if you're running out of memory

3. database performance, especially for pages like find party when  
you have a lot of parties in the database; for Postgres: have you run  
a vacuum since loading a bunch of data, and do you have regularly  
scheduled vacuum calls? databases in general need to be optimized,  
especially initially, but also periodically for all production  
systems; there just isn't any good way around this and it sometimes  
involves some manual effort like watching queries for common slow  
things that could use some additional indices and such

-David


On Aug 18, 2006, at 8:30 AM, Walter Vaughan wrote:

> We have noticed a drastic slowness in building pages that does not  
> seem to be fixed with following the Production Guide instructions  
> on setting the caches.
>
> I realize we have a ton more to learn, but I need to start doing  
> demonstrations of our Data in OFBiz, and I need it to work within  
> expectations.
>
> We are seeing sometimes as long as 29 seconds to finish drawing a  
> page.
>
> We are "svn"ed as of yesterday.
>
> For example, clicking on the Catalog draws the left hand side  
> instantly, but hangs for 10 to 20 seconds sometimes before it  
> displays the "catalog adminstration main page screenlet".
>
> Another example is clicking on Party. I draws the top half  
> instantly, and takes as long as 10 to 30 seconds to display the  
> "parties found" screenlet.
>
> I've included a log that probably isn't interesting till later in  
> the dump
>
> 2006-08-18 14:23:20,017 (TP-Processor8) [     ControlServlet.java:
> 90 :INFO ] The character encoding of the request is: [null]. The  
> character encoding we will use for the request and response is:  
> [UTF-8]
> 2006-08-18 14:23:20,018 (TP-Processor8) [     ControlServlet.java:
> 126:DEBUG] [[[main] Servlet Starting, doing setup- total:0.0,since  
> last(Begin):0.0]]
> 2006-08-18 14:23:20,019 (TP-Processor8) [     ControlServlet.java:
> 175:DEBUG] [[[main] Setup done, doing Event(s) and View(s)- total:
> 0.0,since last([main] Servlet St...):0.0]]
> 2006-08-18 14:23:20,020 (TP-Processor8) [     RequestHandler.java:
> 203:INFO ] [Processing Request]: main
> 2006-08-18 14:23:20,024 (TP-Processor8) [     RequestManager.java:
> 114:INFO ] [RequestManager.getRequestAttribute] Value for attribute  
> "null" of uri "main" not found
> 2006-08-18 14:23:20,025 (TP-Processor8) [     RequestHandler.java:
> 386:INFO ] [RequestHandler.doRequest]: Response is a view.
> 2006-08-18 14:23:20,026 (TP-Processor8) [     RequestHandler.java:
> 538:INFO ] servletName=control, view=main
> 2006-08-18 14:23:20,027 (TP-Processor8) [     ScreenRenderer.java:
> 194:INFO ] Found session attribute that conflicts with parameter  
> name, leaving request parameter in place for name: externalLoginKey
> 2006-08-18 14:23:20,028 (TP-Processor8) [   PrimaryKeyFinder.java:
> 132:INFO ] Returning null because found incomplete primary key in  
> find: [GenericEntity:Product][productId,null()]
> 2006-08-18 14:23:20,352 (TP-Processor8) [  ServiceDispatcher.java:
> 450:DEBUG] [[Sync service finished- total:0.0010,since last(Begin):
> 0.0010]] - 'catalog / getProductCategoryAndLimitedMembers'
> 2006-08-18 14:23:43,452 (TP-Processor8) [     ControlServlet.java:
> 250:DEBUG] [[[main] Done rendering page, Servlet Finished- total:
> 23.433,since last([main] Setup done...):23.433]]
> 2006-08-18 14:23:47,701 (TP-Processor3) [     ControlServlet.java:
> 90 :INFO ] The character encoding of the request is: [null]. The  
> character encoding we will use for the request and response is:  
> [UTF-8]
> 2006-08-18 14:23:47,702 (TP-Processor3) [     ControlServlet.java:
> 126:DEBUG] [[[main] Servlet Starting, doing setup- total:0.0,since  
> last(Begin):0.0]]
> 2006-08-18 14:23:47,703 (TP-Processor3) [     ControlServlet.java:
> 175:DEBUG] [[[main] Setup done, doing Event(s) and View(s)- total:
> 0.0,since last([main] Servlet St...):0.0]]
> 2006-08-18 14:23:47,704 (TP-Processor3) [     RequestHandler.java:
> 203:INFO ] [Processing Request]: main
> 2006-08-18 14:23:47,705 (TP-Processor3) [     RequestManager.java:
> 114:INFO ] [RequestManager.getRequestAttribute] Value for attribute  
> "null" of uri "main" not found
> 2006-08-18 14:23:47,706 (TP-Processor3) [     RequestHandler.java:
> 386:INFO ] [RequestHandler.doRequest]: Response is a view.
> 2006-08-18 14:23:47,706 (TP-Processor3) [     RequestHandler.java:
> 538:INFO ] servletName=control, view=main
> 2006-08-18 14:23:47,707 (TP-Processor3) [     ScreenRenderer.java:
> 194:INFO ] Found session attribute that conflicts with parameter  
> name, leaving request parameter in place for name: externalLoginKey
> 2006-08-18 14:23:47,722 (TP-Processor3) [  ServiceDispatcher.java:
> 450:DEBUG] [[Sync service finished- total:0.013,since last(Begin):
> 0.013]] - 'partymgr / findParty'
> 2006-08-18 14:23:47,769 (TP-Processor3) [  ModelScreenWidget.java:
> 362:INFO ] In the include-screen tag the screen name was empty,  
> ignoring include; in screen [GlobalDecorator]
> 2006-08-18 14:23:53,976 (TP-Processor3) [     ControlServlet.java:
> 250:DEBUG] [[[main] Done rendering page, Servlet Finished- total:
> 6.272,since last([main] Setup done...):6.272]]
> 2006-08-18 14:24:41,021 (TP-Processor2) [     ControlServlet.java:
> 90 :INFO ] The character encoding of the request is: [null]. The  
> character encoding we will use for the request and response is:  
> [UTF-8]
> 2006-08-18 14:24:41,022 (TP-Processor2) [     ControlServlet.java:
> 126:DEBUG] [[[main] Servlet Starting, doing setup- total:0.0,since  
> last(Begin):0.0]]
> 2006-08-18 14:24:41,023 (TP-Processor2) [     ControlServlet.java:
> 175:DEBUG] [[[main] Setup done, doing Event(s) and View(s)- total:
> 0.0,since last([main] Servlet St...):0.0]]
> 2006-08-18 14:24:41,024 (TP-Processor2) [     RequestHandler.java:
> 203:INFO ] [Processing Request]: main
> 2006-08-18 14:24:41,025 (TP-Processor2) [     RequestManager.java:
> 114:INFO ] [RequestManager.getRequestAttribute] Value for attribute  
> "null" of uri "main" not found
> 2006-08-18 14:24:41,026 (TP-Processor2) [     RequestHandler.java:
> 386:INFO ] [RequestHandler.doRequest]: Response is a view.
> 2006-08-18 14:24:41,027 (TP-Processor2) [     RequestHandler.java:
> 538:INFO ] servletName=control, view=main
> 2006-08-18 14:24:41,028 (TP-Processor2) [     ScreenRenderer.java:
> 194:INFO ] Found session attribute that conflicts with parameter  
> name, leaving request parameter in place for name: externalLoginKey
> 2006-08-18 14:24:41,029 (TP-Processor2) [   PrimaryKeyFinder.java:
> 132:INFO ] Returning null because found incomplete primary key in  
> find: [GenericEntity:Product][productId,null()]
> 2006-08-18 14:24:41,252 (TP-Processor2) [  ServiceDispatcher.java:
> 450:DEBUG] [[Sync service finished- total:0.0010,since last(Begin):
> 0.0010]] - 'catalog / getProductCategoryAndLimitedMembers'
> 2006-08-18 14:24:42,732 (TP-Processor2) [     ControlServlet.java:
> 250:DEBUG] [[[main] Done rendering page, Servlet Finished- total:
> 1.708,since last([main] Setup done...):1.708]]

[cjhowe]

There seems to be a bit of peculiarness in your log.

Are you sure you're not trying a custom application?
Current svn will display a logInfo entry for accessing
a screen definition. ie
ScreenFactory.java:118:INFO ] Got 24 screens in 0.571s
from:
file:/C:/apacheOfbiz/applications/party/widget/partymgr/PartyScreens.xml


Yours is missing that.  Are you using a different kind
of view?  If you are, tell us more about that.

--- Walter Vaughan <[hidden email]> wrote:

> We have noticed a drastic slowness in building pages
> that does not seem to be
> fixed with following the Production Guide
> instructions on setting the caches.
>
> I realize we have a ton more to learn, but I need to
> start doing demonstrations
> of our Data in OFBiz, and I need it to work within
> expectations.
>
> We are seeing sometimes as long as 29 seconds to
> finish drawing a page.
>
> We are "svn"ed as of yesterday.
>
> For example, clicking on the Catalog draws the left
> hand side instantly, but
> hangs for 10 to 20 seconds sometimes before it
> displays the "catalog
> adminstration main page screenlet".
>
> Another example is clicking on Party. I draws the
> top half instantly, and takes
> as long as 10 to 30 seconds to display the "parties
> found" screenlet.
>
> I've included a log that probably isn't interesting
> till later in the dump
>
> 2006-08-18 14:23:20,017 (TP-Processor8) [    
> ControlServlet.java:90 :INFO ] The
> character encoding of the request is: [null]. The
> character encoding we will use
> for the request and response is: [UTF-8]
> 2006-08-18 14:23:20,018 (TP-Processor8) [    
> ControlServlet.java:126:DEBUG]
> [[[main] Servlet Starting, doing setup-
> total:0.0,since last(Begin):0.0]]
> 2006-08-18 14:23:20,019 (TP-Processor8) [    
> ControlServlet.java:175:DEBUG]
> [[[main] Setup done, doing Event(s) and View(s)-
> total:0.0,since last([main]
> Servlet St...):0.0]]
> 2006-08-18 14:23:20,020 (TP-Processor8) [    
> RequestHandler.java:203:INFO ]
> [Processing Request]: main
> 2006-08-18 14:23:20,024 (TP-Processor8) [    
> RequestManager.java:114:INFO ]
> [RequestManager.getRequestAttribute] Value for
> attribute "null" of uri "main"
> not found
> 2006-08-18 14:23:20,025 (TP-Processor8) [    
> RequestHandler.java:386:INFO ]
> [RequestHandler.doRequest]: Response is a view.
> 2006-08-18 14:23:20,026 (TP-Processor8) [    
> RequestHandler.java:538:INFO ]
> servletName=control, view=main
> 2006-08-18 14:23:20,027 (TP-Processor8) [    
> ScreenRenderer.java:194:INFO ]
> Found session attribute that conflicts with
> parameter name, leaving request
> parameter in place for name: externalLoginKey
> 2006-08-18 14:23:20,028 (TP-Processor8) [  
> PrimaryKeyFinder.java:132:INFO ]
> Returning null because found incomplete primary key
> in find:
> [GenericEntity:Product][productId,null()]
> 2006-08-18 14:23:20,352 (TP-Processor8) [
> ServiceDispatcher.java:450:DEBUG]
> [[Sync service finished- total:0.0010,since
> last(Begin):0.0010]] - 'catalog /
> getProductCategoryAndLimitedMembers'
> 2006-08-18 14:23:43,452 (TP-Processor8) [    
> ControlServlet.java:250:DEBUG]
> [[[main] Done rendering page, Servlet Finished-
> total:23.433,since last([main]
> Setup done...):23.433]]
> 2006-08-18 14:23:47,701 (TP-Processor3) [    
> ControlServlet.java:90 :INFO ] The
> character encoding of the request is: [null]. The
> character encoding we will use
> for the request and response is: [UTF-8]
> 2006-08-18 14:23:47,702 (TP-Processor3) [    
> ControlServlet.java:126:DEBUG]
> [[[main] Servlet Starting, doing setup-
> total:0.0,since last(Begin):0.0]]
> 2006-08-18 14:23:47,703 (TP-Processor3) [    
> ControlServlet.java:175:DEBUG]
> [[[main] Setup done, doing Event(s) and View(s)-
> total:0.0,since last([main]
> Servlet St...):0.0]]
> 2006-08-18 14:23:47,704 (TP-Processor3) [    
> RequestHandler.java:203:INFO ]
> [Processing Request]: main
> 2006-08-18 14:23:47,705 (TP-Processor3) [    
> RequestManager.java:114:INFO ]
> [RequestManager.getRequestAttribute] Value for
> attribute "null" of uri "main"
> not found
> 2006-08-18 14:23:47,706 (TP-Processor3) [    
> RequestHandler.java:386:INFO ]
> [RequestHandler.doRequest]: Response is a view.
> 2006-08-18 14:23:47,706 (TP-Processor3) [    
> RequestHandler.java:538:INFO ]
> servletName=control, view=main
> 2006-08-18 14:23:47,707 (TP-Processor3) [    
> ScreenRenderer.java:194:INFO ]
> Found session attribute that conflicts with
> parameter name, leaving request
> parameter in place for name: externalLoginKey
> 2006-08-18 14:23:47,722 (TP-Processor3) [
> ServiceDispatcher.java:450:DEBUG]
> [[Sync service finished- total:0.013,since
> last(Begin):0.013]] - 'partymgr /
> findParty'
> 2006-08-18 14:23:47,769 (TP-Processor3) [
> ModelScreenWidget.java:362:INFO ] In
> the include-screen tag the screen name was empty,
> ignoring include; in screen
> [GlobalDecorator]
> 2006-08-18 14:23:53,976 (TP-Processor3) [    
> ControlServlet.java:250:DEBUG]
> [[[main] Done rendering page, Servlet Finished-
> total:6.272,since last([main]
> Setup done...):6.272]]
> 2006-08-18 14:24:41,021 (TP-Processor2) [    
> ControlServlet.java:90 :INFO ] The
> character encoding of the request is: [null]. The
> character encoding we will use
> for the request and response is: [UTF-8]
> 2006-08-18 14:24:41,022 (TP-Processor2) [    
> ControlServlet.java:126:DEBUG]
> [[[main] Servlet Starting, doing setup-
> total:0.0,since last(Begin):0.0]]
> 2006-08-18 14:24:41,023 (TP-Processor2) [    
> ControlServlet.java:175:DEBUG]
> [[[main] Setup done, doing Event(s) and View(s)-
> total:0.0,since last([main]
> Servlet St...):0.0]]
> 2006-08-18 14:24:41,024 (TP-Processor2) [    
> RequestHandler.java:203:INFO ]
> [Processing Request]: main
> 2006-08-18 14:24:41,025 (TP-Processor2) [    
> RequestManager.java:114:INFO ]
> [RequestManager.getRequestAttribute] Value for
> attribute "null" of uri "main"
> not found
> 2006-08-18 14:24:41,026 (TP-Processor2) [    
> RequestHandler.java:386:INFO ]
> [RequestHandler.doRequest]: Response is a view.
> 2006-08-18 14:24:41,027 (TP-Processor2) [    
> RequestHandler.java:538:INFO ]
> servletName=control, view=main
> 2006-08-18 14:24:41,028 (TP-Processor2) [    
> ScreenRenderer.java:194:INFO ]
> Found session attribute that conflicts with
> parameter name, leaving request
> parameter in place for name: externalLoginKey
> 2006-08-18 14:24:41,029 (TP-Processor2) [  
> PrimaryKeyFinder.java:132:INFO ]
> Returning null because found incomplete primary key
> in find:
> [GenericEntity:Product][productId,null()]
> 2006-08-18 14:24:41,252 (TP-Processor2) [
> ServiceDispatcher.java:450:DEBUG]
> [[Sync service finished- total:0.0010,since
> last(Begin):0.0010]] - 'catalog /
> getProductCategoryAndLimitedMembers'
> 2006-08-18 14:24:42,732 (TP-Processor2) [    
> ControlServlet.java:250:DEBUG]
> [[[main] Done rendering page, Servlet Finished-
> total:1.708,since last([main]
> Setup done...):1.708]]
>

[David E Jones-2]

The fact that those are missing is a good sign. It means that the  
timeouts on the screen and other caches have been removed meaning  
those files are cached instead of being read over and over.

So, yes, with production cache settings you should not see those  
messages so the log is as would be expected. This is actually a  
pretty good example of one of very many fairly simple things that  
knowing about makes life a lot easier when working with OFBiz. The  
trick is that there are so many of them... For this sort of thing the  
advanced framework stuff and of course the basic production setup  
guide are quite helpful.

-David


On Aug 18, 2006, at 8:14 PM, Chris Howe wrote:

> There seems to be a bit of peculiarness in your log.
>
> Are you sure you're not trying a custom application?
> Current svn will display a logInfo entry for accessing
> a screen definition. ie
> ScreenFactory.java:118:INFO ] Got 24 screens in 0.571s
> from:
> file:/C:/apacheOfbiz/applications/party/widget/partymgr/
> PartyScreens.xml
>
>
> Yours is missing that.  Are you using a different kind
> of view?  If you are, tell us more about that.
>
> --- Walter Vaughan <[hidden email]> wrote:
>
>> We have noticed a drastic slowness in building pages
>> that does not seem to be
>> fixed with following the Production Guide
>> instructions on setting the caches.
>>
>> I realize we have a ton more to learn, but I need to
>> start doing demonstrations
>> of our Data in OFBiz, and I need it to work within
>> expectations.
>>
>> We are seeing sometimes as long as 29 seconds to
>> finish drawing a page.
>>
>> We are "svn"ed as of yesterday.
>>
>> For example, clicking on the Catalog draws the left
>> hand side instantly, but
>> hangs for 10 to 20 seconds sometimes before it
>> displays the "catalog
>> adminstration main page screenlet".
>>
>> Another example is clicking on Party. I draws the
>> top half instantly, and takes
>> as long as 10 to 30 seconds to display the "parties
>> found" screenlet.
>>
>> I've included a log that probably isn't interesting
>> till later in the dump
>>
>> 2006-08-18 14:23:20,017 (TP-Processor8) [
>> ControlServlet.java:90 :INFO ] The
>> character encoding of the request is: [null]. The
>> character encoding we will use
>> for the request and response is: [UTF-8]
>> 2006-08-18 14:23:20,018 (TP-Processor8) [
>> ControlServlet.java:126:DEBUG]
>> [[[main] Servlet Starting, doing setup-
>> total:0.0,since last(Begin):0.0]]
>> 2006-08-18 14:23:20,019 (TP-Processor8) [
>> ControlServlet.java:175:DEBUG]
>> [[[main] Setup done, doing Event(s) and View(s)-
>> total:0.0,since last([main]
>> Servlet St...):0.0]]
>> 2006-08-18 14:23:20,020 (TP-Processor8) [
>> RequestHandler.java:203:INFO ]
>> [Processing Request]: main
>> 2006-08-18 14:23:20,024 (TP-Processor8) [
>> RequestManager.java:114:INFO ]
>> [RequestManager.getRequestAttribute] Value for
>> attribute "null" of uri "main"
>> not found
>> 2006-08-18 14:23:20,025 (TP-Processor8) [
>> RequestHandler.java:386:INFO ]
>> [RequestHandler.doRequest]: Response is a view.
>> 2006-08-18 14:23:20,026 (TP-Processor8) [
>> RequestHandler.java:538:INFO ]
>> servletName=control, view=main
>> 2006-08-18 14:23:20,027 (TP-Processor8) [
>> ScreenRenderer.java:194:INFO ]
>> Found session attribute that conflicts with
>> parameter name, leaving request
>> parameter in place for name: externalLoginKey
>> 2006-08-18 14:23:20,028 (TP-Processor8) [
>> PrimaryKeyFinder.java:132:INFO ]
>> Returning null because found incomplete primary key
>> in find:
>> [GenericEntity:Product][productId,null()]
>> 2006-08-18 14:23:20,352 (TP-Processor8) [
>> ServiceDispatcher.java:450:DEBUG]
>> [[Sync service finished- total:0.0010,since
>> last(Begin):0.0010]] - 'catalog /
>> getProductCategoryAndLimitedMembers'
>> 2006-08-18 14:23:43,452 (TP-Processor8) [
>> ControlServlet.java:250:DEBUG]
>> [[[main] Done rendering page, Servlet Finished-
>> total:23.433,since last([main]
>> Setup done...):23.433]]
>> 2006-08-18 14:23:47,701 (TP-Processor3) [
>> ControlServlet.java:90 :INFO ] The
>> character encoding of the request is: [null]. The
>> character encoding we will use
>> for the request and response is: [UTF-8]
>> 2006-08-18 14:23:47,702 (TP-Processor3) [
>> ControlServlet.java:126:DEBUG]
>> [[[main] Servlet Starting, doing setup-
>> total:0.0,since last(Begin):0.0]]
>> 2006-08-18 14:23:47,703 (TP-Processor3) [
>> ControlServlet.java:175:DEBUG]
>> [[[main] Setup done, doing Event(s) and View(s)-
>> total:0.0,since last([main]
>> Servlet St...):0.0]]
>> 2006-08-18 14:23:47,704 (TP-Processor3) [
>> RequestHandler.java:203:INFO ]
>> [Processing Request]: main
>> 2006-08-18 14:23:47,705 (TP-Processor3) [
>> RequestManager.java:114:INFO ]
>> [RequestManager.getRequestAttribute] Value for
>> attribute "null" of uri "main"
>> not found
>> 2006-08-18 14:23:47,706 (TP-Processor3) [
>> RequestHandler.java:386:INFO ]
>> [RequestHandler.doRequest]: Response is a view.
>> 2006-08-18 14:23:47,706 (TP-Processor3) [
>> RequestHandler.java:538:INFO ]
>> servletName=control, view=main
>> 2006-08-18 14:23:47,707 (TP-Processor3) [
>> ScreenRenderer.java:194:INFO ]
>> Found session attribute that conflicts with
>> parameter name, leaving request
>> parameter in place for name: externalLoginKey
>> 2006-08-18 14:23:47,722 (TP-Processor3) [
>> ServiceDispatcher.java:450:DEBUG]
>> [[Sync service finished- total:0.013,since
>> last(Begin):0.013]] - 'partymgr /
>> findParty'
>> 2006-08-18 14:23:47,769 (TP-Processor3) [
>> ModelScreenWidget.java:362:INFO ] In
>> the include-screen tag the screen name was empty,
>> ignoring include; in screen
>> [GlobalDecorator]
>> 2006-08-18 14:23:53,976 (TP-Processor3) [
>> ControlServlet.java:250:DEBUG]
>> [[[main] Done rendering page, Servlet Finished-
>> total:6.272,since last([main]
>> Setup done...):6.272]]
>> 2006-08-18 14:24:41,021 (TP-Processor2) [
>> ControlServlet.java:90 :INFO ] The
>> character encoding of the request is: [null]. The
>> character encoding we will use
>> for the request and response is: [UTF-8]
>> 2006-08-18 14:24:41,022 (TP-Processor2) [
>> ControlServlet.java:126:DEBUG]
>> [[[main] Servlet Starting, doing setup-
>> total:0.0,since last(Begin):0.0]]
>> 2006-08-18 14:24:41,023 (TP-Processor2) [
>> ControlServlet.java:175:DEBUG]
>> [[[main] Setup done, doing Event(s) and View(s)-
>> total:0.0,since last([main]
>> Servlet St...):0.0]]
>> 2006-08-18 14:24:41,024 (TP-Processor2) [
>> RequestHandler.java:203:INFO ]
>> [Processing Request]: main
>> 2006-08-18 14:24:41,025 (TP-Processor2) [
>> RequestManager.java:114:INFO ]
>> [RequestManager.getRequestAttribute] Value for
>> attribute "null" of uri "main"
>> not found
>> 2006-08-18 14:24:41,026 (TP-Processor2) [
>> RequestHandler.java:386:INFO ]
>> [RequestHandler.doRequest]: Response is a view.
>> 2006-08-18 14:24:41,027 (TP-Processor2) [
>> RequestHandler.java:538:INFO ]
>> servletName=control, view=main
>> 2006-08-18 14:24:41,028 (TP-Processor2) [
>> ScreenRenderer.java:194:INFO ]
>> Found session attribute that conflicts with
>> parameter name, leaving request
>> parameter in place for name: externalLoginKey
>> 2006-08-18 14:24:41,029 (TP-Processor2) [
>> PrimaryKeyFinder.java:132:INFO ]
>> Returning null because found incomplete primary key
>> in find:
>> [GenericEntity:Product][productId,null()]
>> 2006-08-18 14:24:41,252 (TP-Processor2) [
>> ServiceDispatcher.java:450:DEBUG]
>> [[Sync service finished- total:0.0010,since
>> last(Begin):0.0010]] - 'catalog /
>> getProductCategoryAndLimitedMembers'
>> 2006-08-18 14:24:42,732 (TP-Processor2) [
>> ControlServlet.java:250:DEBUG]
>> [[[main] Done rendering page, Servlet Finished-
>> total:1.708,since last([main]
>> Setup done...):1.708]]
>>
>

[Walter Vaughan]

>> --- Walter Vaughan <[hidden email]> wrote:
>>
>>> We have noticed a drastic slowness in building pages
>>> that does not seem to be
>>> fixed with following the Production Guide
>>> instructions on setting the caches.

After seeing the drastic slowdown after testing with postgreSQL, we tested on a
vastly underpowered box (Athlon-1.2Ghz,256Meg,MySQL5.1,JDK1.4.2,FreeBSD6.1) with
the same data we had loaded, and ofBiz works just fine.

The slow server in question is a dual Xeon Intel Server with all the goodies of
two years ago... 4 drive RAID 5, 1 Gig Memory, 100% Intel, 'cept the drives. The
same OS, but the JDK is 1.5 from the freeBSD foundation. So last night did a
Vacuum on the PostgreSQL, and followed its instructions, tried to restart
PostgreSQL and it failed with a very cryptic "unable to start postmaster".
Rebooted the server, and even it wouldn't restart pgsql. Time to go back to
MySQL. We've more problems than slow query times.

With MySQL we're back to the behavior before, except the page delays are
somewhat random, and only last a second or two. A good example would be clicking
radio buttons in the Party Lookup area changing from Postal to Telecom.

So, I'm going to dump the native 1.5 JDK and fall back to the Linux based 1.4.2
and see what that gets us.

Else that or I demo the system using a computer that was picked up for $20 at
the local GoodWill thrift shop vs a $2500 server.
--
Walter

[David E Jones-2]

It really is amazing the difference that things on a software level  
can make, and even seemingly trivial settings...

I don't know if you guys are equipped to do this, but the only real  
way to find out what is slow is to measure different things and see  
what is causing the slowness. This can be done with log messages on  
the simplest level, and with a profiler to really get an obscene  
amount of information.

Doing measurements is the only way to avoid flailing around and  
randomly changing things, which seems to be more or less the stage  
your at right now.

Best of luck,
-David


On Aug 19, 2006, at 7:32 AM, Walter Vaughan wrote:

>>> --- Walter Vaughan <[hidden email]> wrote:
>>>
>>>> We have noticed a drastic slowness in building pages
>>>> that does not seem to be
>>>> fixed with following the Production Guide
>>>> instructions on setting the caches.
>
> After seeing the drastic slowdown after testing with postgreSQL, we  
> tested on a vastly underpowered box (Athlon-1.2Ghz,
> 256Meg,MySQL5.1,JDK1.4.2,FreeBSD6.1) with the same data we had  
> loaded, and ofBiz works just fine.
>
> The slow server in question is a dual Xeon Intel Server with all  
> the goodies of two years ago... 4 drive RAID 5, 1 Gig Memory, 100%  
> Intel, 'cept the drives. The same OS, but the JDK is 1.5 from the  
> freeBSD foundation. So last night did a Vacuum on the PostgreSQL,  
> and followed its instructions, tried to restart PostgreSQL and it  
> failed with a very cryptic "unable to start postmaster". Rebooted  
> the server, and even it wouldn't restart pgsql. Time to go back to  
> MySQL. We've more problems than slow query times.
>
> With MySQL we're back to the behavior before, except the page  
> delays are somewhat random, and only last a second or two. A good  
> example would be clicking radio buttons in the Party Lookup area  
> changing from Postal to Telecom.
>
> So, I'm going to dump the native 1.5 JDK and fall back to the Linux  
> based 1.4.2 and see what that gets us.
>
> Else that or I demo the system using a computer that was picked up  
> for $20 at the local GoodWill thrift shop vs a $2500 server.
> --
> Walter