Rajat Gupta
Rajat Gupta

Reputation: 26597

FacesServlet.service() method eating too much time while serving requests (high self-time)

I was just trying out some profiling experiments with my JSF project using Netbeans based Profiler. However I found a very surprising results. I found JSF's FacesServlet.service() method to be consuming most of the time while requests were being served. I do serve content from databases into my JSF pages but still I found major time lag was due to high self time of service() method.

Here is the snapshot of the profiling results:- See the high self-time of FacesServlet service() method

Why is this happening, what's happening so expensive within this method that causes such high self time ?

I am running Myfaces 2.1.12 in Production mode on Tomcat 7.0.42.


Edit:

As rightly pointed out by @mkienenb in his answer below, during the above profiling test I excluded the org.apache.myfaces methods, so I did a fresh profiling test & I'm posting below the new result snapshot.

enter image description here

But you can still see that a lot of time overhead is caused due to self times of Myfaces/JSF methods.

Upvotes: 4

Views: 1071

Answers (2)

mkienenb
mkienenb

Reputation: 56

I'm not an expert on profiling, but I'm pretty sure that "self-time" includes all methods that are not explicitly profiled elsewhere. For some reason it appears that you are not profiling "org.apache.myfaces" methods individually, but only javax.faces methods.

So that's going to make all JSF execution time show up under javax.faces.webapp.FacesServlet.services().

You need to adjust your package exclusion choices. I don't use NetBeans so I can't tell you specifically how that's done.

Upvotes: 2

Howard
Howard

Reputation: 792

Hmmm, what are the parameters of FacesServlet.service()? is that servlet request and servlet response? seems like a typical request from your browser and response from your app/server.

It is quite obvious that your code-and-or-usage-of-your-dependencies are the cause of the time it takes for FacesServlet.service() to complete. Wow, it seems as though your usage of prettyfaces dependency is causing most of the lengthy time it takes for FacesServlet.service() to complete.

On Sat, Sep 7, 2013 at 2:24 AM, Anton Gavazuk wrote:

Process an incoming request, and create the corresponding response, by executing the request processing lifecycle.

If the request and response arguments to this method are not instances of HttpServletRequest and HttpServletResponse, respectively, the results of invoking this method are undefined.

This method must respond to requests that start with the following strings by invoking the sendError method on the response argument (cast to HttpServletResponse), passing the code HttpServletResponse.SC_NOT_FOUND as the argument.

So this method is actually wrapping up all underlying processing: jsf actions, business services, interaction with db - thus its time is always the biggest

In response to OP and to demonstrate what Anton (from myfaces list) stated above,

(1) Prior to beginning this request, my browser displayed the 'session timeout' page, so I clicked OK, which did a simple request to the server to respond with the login page. the screen captures below will show you that, such a simple request, yielded response time so quick that FacesServlet.service() was not found.

Figure 1a

Figure 1b

(2) After the login page was rendered in my browser, I clicked the Login button and my app does several operations (check database for user id, verify password stored in database, and then navigates to and renders a page which does a database retrieval, which can take a few seconds, depending on the number of user actions completed on the current date (it is user audit trail data/page), and of course, the page is rendered in the browser, after all of that. I searched for FacesServlet.service() several times until no more occurrences found. in the screen captures below, you will see that FacesServlet.service() 'time' is caused by the time it takes to complete other/underlying/invoked operations/processes.

Figure 2a

Figure 2b

Figure 2c

Figure 2d

Figure 2e

Figure 2f

Figure 2g

(3) On the Audit Trail page, I clicked an option which will invoke an AJAX request/response, which will do a database retrieval that can/will take longer than the database retrieval in #2 above, and then the AJAX response will be rendered in the browser. The screen captures below will show you, again, that FacesServlet.service() 'time' is caused by the time it takes to complete other/underlying/invoked operations/processes.

Figure 3a

Figure 3b

(4) Next/finally, I decided to click a menubar option, which does a database retrieval to show data in the database, based on the current date, and navigates to and/or renders a different page in the browser. The screen captures below will show you, again, that FacesServlet.service() 'time' is caused by the time it takes to complete other/underlying/invoked operations/processes.

Figure 4a

Figure 4b

Figure 4c

I am running Myfaces 2.1.12 in Production mode on Tomcat 7.0.42.

Me too...via TomEE+ 1.6.0 'snapshot' (2013-September-06 version/build)

Upvotes: 1

Related Questions