Datatable pagination : long APPLY_REQUEST_VALUES phase

UI Components for JSF
mask_hot
Posts: 34
Joined: 27 May 2011, 10:52

08 Jul 2012, 00:37

Hi,

I'm using PF 3.3.1 and made a quite classic LazyLoading Datatable.
I remarked the more big my entities were, the longer is the APPLY_REQUEST_VALUES phase while paginating.

For example, for an entity, the time for changing page is 48s (yes seconds!). The SQL request is 5s of it and the APPLY_REQUEST_VALUES is more than 40s long.
For another entity, lighter, the tme for changing page is 12s, SQL is less than 300ms and APPLY REQUEST VALUES is ~10s.

I'd like to know if it's normal.

It's the first time I get those timings. I was used to use a local and light mysql DB for another project and never had this issue. Now I'm using a bigger remote mysql DB and have this really strange respons time, but as I said the SQL time is note really huge (from 2% to 12% of total time).

smithh032772
Posts: 6144
Joined: 10 Sep 2011, 21:10

08 Jul 2012, 05:23

Please reply with your xhtml and supporting bean(s).
Howard

PrimeFaces 6.0, Extensions 6.0.0, Push (Atmosphere 2.4.0)
TomEE+ 1.7.4 (Tomcat 7.0.68), MyFaces Core 2.2.9, JDK8
JUEL 2.2.7 | OmniFaces | EclipseLink-JPA/Derby | Chrome

Java EE 6 Tutorial|NetBeans|Google|Stackoverflow|PrimeFaces|Apache

mask_hot
Posts: 34
Joined: 27 May 2011, 10:52

10 Jul 2012, 01:12

datatable

Code: Select all

<h:form id="dtbHotel">
            <p:panel header="#{bundle.Hotel}">
                <!--@elvariable id="item" type="com.reservit.com.reservit.model.hotel.Hotel"-->
                <p:dataTable id="dtb"
                             value="#{hotelController.lazyModel}"
                             var="item"
                             selection="#{hotelController.selected}"
                             selectionMode="single"
                             sortBy="#{item.name}"
                             rowKey="#{item.hotelid}"
                             paginator="true" rows="25"
                             paginatorTemplate="{CurrentPageReport}  {FirstPageLink} {PreviousPageLink} {PageLinks} {NextPageLink} {LastPageLink} {RowsPerPageDropdown}"
                             rowsPerPageTemplate="10,25,50"
                             scrollHeight="250"
                             emptyMessage="#{bundle.NoDataFound}"
                             paginatorAlwaysVisible="false"
                        >
                    <!-- >
                    <pe:paginator-->
                    <!--listener="#{dataTableController.doSomething}"-->
                    <!--update="_mainForm_messages"-->
                    <p:ajax event="page"
                            onstart="blockUIWidget2.block()"
                            oncomplete="blockUIWidget2.unblock()"/>
                    <p:ajax event="sort"
                            onstart="blockUIWidget2.block()"
                            oncomplete="blockUIWidget2.unblock()"/>
                    <!--<p:ajax event="filter"-->
                    <!--onstart="blockUIWidget2.block()"-->
                    <!--oncomplete="blockUIWidget2.unblock()"/>-->
                    <p:ajax event="rowSelect"
                            listener="#{hotelController.onRowSelect}"
                            update="tb"/>
                    <p:ajax event="rowUnselect"
                            listener="#{hotelController.onRowUnselect}"
                            update="tb"/>
                    <!--<p:ajax event="toggleSelect"-->
                    <!--listener="#{hotelController.onRowUnselect}"-->
                    <!--update="tb"/>-->
                    <!--<p:ajax event="colResize"-->
                    <!--listener="#{hotelController.onRowUnselect}"-->
                    <!--update="tb"/>-->
                    <!--<p:ajax event="colReorder"-->
                    <!--listener="#{hotelController.onRowUnselect}"-->
                    <!--update="tb"/>-->
                    <!--<p:ajax event="rowSelectRadio"-->
                    <!--listener="#{hotelController.onRowUnselect}"-->
                    <!--update="tb"/>-->
                    <!--<p:ajax event="rowSelectCheckbox"-->
                    <!--listener="#{hotelController.onRowUnselect}"-->
                    <!--update="tb"/>-->
                    <!--rowUnselectCheckbox-->
                    <!--rowDblselect-->
                    <f:facet name="header">
                        <!--<h:outputText id="sel1" value="#{empty hotelController.selected.id}"/>-->
                        <!--<h:outputText id="sel2" value="#{hotelController.selected.name}"/>-->
                        <!--<p:menubar id="tb">-->
                        <p:toolbar id="tb">
                            <p:toolbarGroup align="left">
                                <p:commandButton icon="ui-icon-document"
                                                 value="#{bundle.ViewLink}"
                                                 action="#{hotelController.prepareView}"
                                                 disabled="#{empty hotelController.selected.hotelid}"/>
                                <p:commandButton icon="ui-icon ui-icon-document"
                                                 value="#{bundle.CreateLink}"
                                                 action="#{hotelController.prepareCreate}"
                                                 immediate="true"/>
                                <p:commandButton icon="ui-icon ui-icon-document"
                                                 value="#{bundle.EditLink}"
                                                 action="#{hotelController.prepareEdit}"
                                                 disabled="#{empty hotelController.selected.hotelid}"/>
                                <p:commandButton icon="ui-icon ui-icon-document"
                                                 value="#{bundle.DeleteLink}"
                                                 action="#{hotelController.prepareDestroy}"
                                                 disabled="#{empty hotelController.selected.hotelid}"/>
                            </p:toolbarGroup>
                        </p:toolbar>

                        <!--</p:menubar>-->
                    </f:facet>
                    <p:column sortBy="#{item.hotelid}"
                              filterBy="#{item.hotelid}"
                              headerText="#{bundle.ListHotelTitle_hotelid}">
                        <h:outputText value="#{item.hotelid}"/>
                    </p:column>
                    <p:column sortBy="#{item.name}"
                              filterBy="#{item.name}"
                              headerText="#{bundle.ListHotelTitle_name}">
                        <h:outputText value="#{item.name}"/>
                    </p:column>
                    <p:column sortBy="#{item.nbroom}"
                              filterBy="#{item.nbroom}"
                              headerText="#{bundle.ListHotelTitle_nbroom}">
                        <h:outputText value="#{item.nbroom}"/>
                    </p:column>
                    <p:column sortBy="#{item.city}"
                              filterBy="#{item.city}"
                              headerText="#{bundle.ListHotelTitle_city}">
                        <h:outputText value="#{item.city}"/>
                    </p:column>
                    <p:column sortBy="#{item.country}"
                              filterBy="#{item.country}"
                              headerText="#{bundle.ListHotelTitle_country}">
                        <h:outputText value="#{item.country}"/>
                    </p:column>
                    <!--                    <p:column sortBy="#{item.dtCreat}"
                              filterBy="#{item.dtCreat}"
                              headerText="#{bundle.ListHotelTitle_dtCreat}" >
                        <h:outputText value="#{item.dtCreat}">
                            <f:convertDateTime type="both" dateStyle="medium" />
                        </h:outputText>
                    </p:column>
                    <p:column sortBy="#{item.dtModif}"
                              filterBy="#{item.dtModif}"
                              headerText="#{bundle.ListHotelTitle_dtModif}" >
                        <h:outputText value="#{item.dtModif}">
                            <f:convertDateTime type="both" dateStyle="medium" />
                        </h:outputText>
                    </p:column>-->
                    <f:facet name="footer">

                    </f:facet>
                </p:dataTable>
            </p:panel>
            <pe:blockUI target="dtb" content="blockUIContent" widgetVar="blockUIWidget2"/>

            <h:panelGrid id="blockUIContent" columns="2" style="display: none;">
                <h:graphicImage library="images" name="ajax-loader1.gif"
                                style="margin-right: 12px; vertical-align: middle;"/>
                <h:outputText value="#{bundle.Loading}" style="white-space: nowrap;"/>
            </h:panelGrid>
        </h:form>
managed bean

Code: Select all

@Interceptors({AuditInterceptor.class, LoggingInterceptor.class})
@ManagedBean(name = "hotelController")
@ViewScoped
public class HotelController extends AbstractController<Hotel>
        implements Serializable {

    @Inject
    private Logger LOGGER;

    @Inject
    private HotelEJB ejbFacade;

    public HotelController() {
    }

    @PostConstruct
    private void postConstruct() {
//        findAll();
    }

    @PreDestroy
    private void preDestroy() {
//        super.infoDestroy();
    }

    @Override
    public Hotel getSelected() {
        if (current == null) {
            current = new Hotel();
            selectedItemIndex = -1;
        }
        return current;
    }

    @Override
    public HotelEJB getFacade() {
        return ejbFacade;
    }

    @Override
    public String prepareEdit() {
        id = current.getId();
        return "pretty:editHotel";
    }

    @Override
    public String prepareView() {
        id = current.getId();
        return "pretty:viewHotel";
    }

    @Override
    public String prepareList() {
        return "pretty:listHotel";
    }

    @Override
    public String prepareCreate() {
        current = new Hotel();
        id = null;
        selectedItemIndex = -1;
        return "pretty:createHotel";
    }

    @Override
    public void onRowSelect(SelectEvent event) {
        super.onRowSelect(event);
        Hotel o = (Hotel) event.getObject();
        LOGGER.debug("selected {}", getSelected().getName());
        JsfUtil.addInfoMessage(getSelected().getName(), "Selected");
    }

    @Override
    public void onRowUnselect(UnselectEvent event) {
        super.onRowUnselect(event);
        Hotel o = (Hotel) event.getObject();
        JsfUtil.addInfoMessage(o.getName(), "Unselected");
    }

    public void setLOGGER(Logger LOGGER) {
        this.LOGGER = LOGGER;
    }
}
The AbstractController

Code: Select all

@Interceptors({ AuditInterceptor.class, LoggingInterceptor.class })
public abstract class AbstractController<T>
        extends AbstractBackingBean {
    public final static String PRETTY_PREFIX = "pretty:";
    protected List             items         = new ArrayList<T>();
    private List<T>            lazyItems     = new ArrayList<T>();
    @Inject
    private Logger             LOGGER;
    protected T                current;

    //
//  @URLQueryParameter("id")
    Integer id;

    //
    private LazyDataModel<T> lazyModel;

    // private Boolean select;
    protected int selectedItemIndex;

    public AbstractController() {

//      init();
    }

    public void setLazyModel(LazySelectableDataModel<T> lazyModel) {
        this.lazyModel = lazyModel;
    }

    public void setLazyItems(List<T> lazyItems) {
        this.lazyItems = lazyItems;
    }

    protected String getPrettyId(String id) {
        StringBuilder sb = new StringBuilder();

        sb.append(PRETTY_PREFIX).append(id);

        return sb.toString();
    }

    public void initLazyModel() {
        if (LOGGER.isDebugEnabled()) {
            LOGGER.debug("initLazyModel");
        }

        lazyModel = new LazyDataModel<T>() {
            @Override
            public List<T> load(int first, int pageSize, String sortField, SortOrder sortOrder,
                                Map<String, String> filters) {
                if (LOGGER.isDebugEnabled()) {
                    LOGGER.debug("Loading the lazy data between " + first + " " + pageSize);
                }

                try {
                    lazyItems = getFacade().findAllLazy(first, pageSize, sortField,
                            sortOrder.equals(SortOrder.ASCENDING), filters);

                    /**
                     * In a real application, this number should be resolved by a projection query
                     */
                    int count = getFacade().countLazy(filters);

                    if (LOGGER.isDebugEnabled()) {
                        LOGGER.debug("nb items " + lazyItems.size() + " count " + count);
                    }

                    lazyModel.setRowCount(count);
                } catch (Exception e) {
                    LOGGER.error("LazyLoad", e);
                    JsfUtil.addErrorMessage("LazyLoad", e.getMessage());
                }

                return lazyItems;
            }
            @Override
            public Object getRowKey(T t) {
                LOGGER.debug("getRowkey {}", toString());

                return ((ITEntity) t).getId();
            }
            @Override
            public T getRowData(String rowKey) {
                LOGGER.debug("getRowData {}", rowKey);

                return rowKey.equals("null")
                       ? null
                       : (T) getFacade().find(Integer.parseInt(rowKey));
            }
        };
    }

    public abstract AbstractEJB getFacade();

    public T getSelected() {
        return current;
    }

    public void setSelected(T t) {
        current = t;
    }

    public void onRowSelect(SelectEvent event) {
        if (LOGGER.isDebugEnabled()) {
            LOGGER.debug("onRowSelect");
        }

//      select = Boolean.TRUE;

        current = (T) event.getObject();
    }

    public void onRowUnselect(UnselectEvent event) {
        if (LOGGER.isDebugEnabled()) {
            LOGGER.debug("onRowUnselect");
        }

//      select = Boolean.FALSE;
        current = null;
    }

    public String prepareEdit() {
        return "Edit?faces-redirect=true";
    }

    public String prepareView() {
        return "View?faces-redirect=true";
    }

    public String prepareCreate() {
        return "Create?faces-redirect=true";
    }

    public String prepareList() {
        if (LOGGER.isDebugEnabled()) {
            LOGGER.debug("prepareList");
        }

        initLazyModel();

//      setSelect(Boolean.FALSE);
        return "List?faces-redirect=true";
    }

    protected void findAll() {
        try {
            items = getFacade().findAll();
        } catch (Exception e) {
            LOGGER.error("FindAll", e);
            JsfUtil.addErrorMessage("FindAll", e.getMessage());
        }
    }

    public String destroy() {
        try {
            getFacade().remove(current);

            return prepareList();
        } catch (Exception e) {
            LOGGER.error("Destroy", e);
            JsfUtil.addErrorMessage("Destroy", e.getMessage());

            return null;
        }
    }

    public String create() {
        if (LOGGER.isDebugEnabled()) {
            LOGGER.debug("create {}", current.getClass());
        }

        try {
            getFacade().create(current);
            JsfUtil.addSuccessMessage(ResourceBundle.getBundle("/Bundle").getString("FamTeamCreated"));

            return prepareView();
        } catch (Exception e) {
            JsfUtil.addErrorMessage(e, ResourceBundle.getBundle("/Bundle").getString("PersistenceErrorOccured"));

            return null;
        }
    }

    public String update() {
        if (LOGGER.isDebugEnabled()) {
            LOGGER.debug("update {}", current);
        }

        try {
            getFacade().edit(current);
            JsfUtil.addSuccessMessage("Update Done");    // ResourceBundle.getBundle("/Bundle").getString("FamTeamUpdated"));
        } catch (Exception e) {
            JsfUtil.addErrorMessage(e, "Update Failed");    // ResourceBundle.getBundle("/Bundle").getString("PersistenceErrorOccured"));

            return null;
        }

        return prepareView();
    }

    public String updateAndNoRedirect() {
        if (LOGGER.isDebugEnabled()) {
            LOGGER.debug("updateAndNoRedirect {} ", current);
        }

        try {
            getFacade().edit(current);
            JsfUtil.addSuccessMessage("Update Done");    // ResourceBundle.getBundle("/Bundle").getString("FamTeamUpdated"));
        } catch (Exception e) {
            JsfUtil.addErrorMessage(e, "Update Failed");    // ResourceBundle.getBundle("/Bundle").getString("PersistenceErrorOccured"));

            return null;
        }

        return null;
    }

    // @URLAction(phaseId = PhaseId.RENDER_RESPONSE, onPostback = false)
    public String loadAction() {
        if (LOGGER.isDebugEnabled()) {
            LOGGER.debug("loadAction id : {}", id);
        }

        if (id != null) {
            try {
                current = (T) getFacade().find(id);

                return null;
            } catch (Exception e) {
                LOGGER.error("Load Action", e);
                JsfUtil.addErrorMessage(e, "Load Action id=" + id);

                return "pretty:";
            }
        } else {
            JsfUtil.addErrorMessage("Load Action id NULL");

            return "pretty:";
        }
    }

    public String destroyAndView() {
        performDestroy();

//      recreateModel();
//      updateCurrentItem();
        if (selectedItemIndex >= 0) {
            return prepareView();
        } else {

            // all items were removed - go back to list
//          recreateModel();
            return prepareList();
        }
    }

    private void performDestroy() {
        try {
            getFacade().remove(current);
            JsfUtil.addSuccessMessage(ResourceBundle.getBundle("/Bundle").getString("HotelDeleted"));
        } catch (Exception e) {
            JsfUtil.addErrorMessage(e, ResourceBundle.getBundle("/Bundle").getString("PersistenceErrorOccured"));
        }
    }

    public void testAction(ActionEvent actionEvent) {
        JsfUtil.addSuccessMessage("test Action", actionEvent.getComponent().getClientId());
    }

    protected void infoDestroy() {
        JsfUtil.addInfoMessage("Votre session a expiré. Veuillez vous re-logguer.", "Attention!");
    }

    public void setLOGGER(Logger LOGGER) {
        this.LOGGER = LOGGER;
    }
}
For this one, I have the following traces :

Code: Select all

BEFORE PHASE RESTORE_VIEW 1
[#|2012-07-10T01:05:58.219+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:05:58.219 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - AFTER PHASE RESTORE_VIEW 1
[#|2012-07-10T01:05:58.220+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:05:58.220 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - BEFORE PHASE APPLY_REQUEST_VALUES 2
[#|2012-07-10T01:06:08.101+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.101 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - AFTER PHASE APPLY_REQUEST_VALUES 2
[#|2012-07-10T01:06:08.101+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.101 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - BEFORE PHASE PROCESS_VALIDATIONS 3
[#|2012-07-10T01:06:08.105+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.105 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - AFTER PHASE PROCESS_VALIDATIONS 3
[#|2012-07-10T01:06:08.106+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.106 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - BEFORE PHASE UPDATE_MODEL_VALUES 4
[#|2012-07-10T01:06:08.108+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.108 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - AFTER PHASE UPDATE_MODEL_VALUES 4
[#|2012-07-10T01:06:08.108+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.108 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - BEFORE PHASE INVOKE_APPLICATION 5
[#|2012-07-10T01:06:08.109+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.109 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - AFTER PHASE INVOKE_APPLICATION 5
[#|2012-07-10T01:06:08.109+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.109 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - BEFORE PHASE RENDER_RESPONSE 6
[#|2012-07-10T01:06:08.119+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.119 [http-thread-pool-8080(1)] DEBUG c.r.j.c.AbstractController - Loading the lazy data between 25 25
[#|2012-07-10T01:06:08.120+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.120 [http-thread-pool-8080(1)] DEBUG c.r.i.LoggingInterceptor - Entering com.reservit.ejb.HotelEJB.findAllLazy
[#|2012-07-10T01:06:08.120+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.120 [http-thread-pool-8080(1)] DEBUG c.r.e.AbstractEJB - first 25 pageSize 25
[#|2012-07-10T01:06:08.121+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.121 [http-thread-pool-8080(1)] DEBUG c.r.e.AbstractEJB - sortField name sortOrder true
[#|2012-07-10T01:06:08.159+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.159 [http-thread-pool-8080(1)] DEBUG c.r.e.AbstractEJB - nb result 25
[#|2012-07-10T01:06:08.159+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.159 [http-thread-pool-8080(1)] DEBUG c.r.i.LoggingInterceptor - Ending com.reservit.ejb.HotelEJB.findAllLazy
[#|2012-07-10T01:06:08.160+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.159 [http-thread-pool-8080(1)] DEBUG c.r.i.AuditInterceptor - findAllLazy took 39 milliseconds.
[#|2012-07-10T01:06:08.161+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.160 [http-thread-pool-8080(1)] DEBUG c.r.i.LoggingInterceptor - Entering com.reservit.ejb.HotelEJB.countLazy
[#|2012-07-10T01:06:08.180+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.180 [http-thread-pool-8080(1)] DEBUG c.r.i.LoggingInterceptor - Ending com.reservit.ejb.HotelEJB.countLazy
[#|2012-07-10T01:06:08.180+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.180 [http-thread-pool-8080(1)] DEBUG c.r.i.AuditInterceptor - countLazy took 20 milliseconds.
[#|2012-07-10T01:06:08.181+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.181 [http-thread-pool-8080(1)] DEBUG c.r.j.c.AbstractController - nb items 25 count 171802
[#|2012-07-10T01:06:08.199+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.199 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - AFTER PHASE RENDER_RESPONSE 6
As you can see, 10s for APPLY REQUEST VALUES.

kukeltje
Expert Member
Posts: 9605
Joined: 17 Jun 2010, 13:34
Location: Netherlands

10 Jul 2012, 08:24

I would have been interested in your own log lines as well. e.g. how often is this one called?

Code: Select all

@Override
            public T getRowData(String rowKey) {
                LOGGER.debug("getRowData {}", rowKey);

                return rowKey.equals("null")
                       ? null
                       : (T) getFacade().find(Integer.parseInt(rowKey));
            }
        };
and what does it do? Look up the individiual entities in the DB?

mask_hot
Posts: 34
Joined: 27 May 2011, 10:52

10 Jul 2012, 12:46

In fact, it might be never called as I can't find any log about it when I paginate or I select a row ... :shock:

kukeltje
Expert Member
Posts: 9605
Joined: 17 Jun 2010, 13:34
Location: Netherlands

10 Jul 2012, 18:03

Ok, then which of your methods is either called a lot, or takes long? You should be able to extact that from your logging can you?

mask_hot
Posts: 34
Joined: 27 May 2011, 10:52

10 Jul 2012, 19:39

That's the matter, I have no idea of what it take so long.

I gave you all the logs I have.
As you can see the problem is here :
[#|2012-07-10T01:05:58.220+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:05:58.220 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - BEFORE PHASE APPLY_REQUEST_VALUES 2
[#|2012-07-10T01:06:08.101+0200|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=20;_ThreadName=Thread-10;|01:06:08.101 [http-thread-pool-8080(1)] DEBUG c.r.j.c.BasePhaseListener - AFTER PHASE APPLY_REQUEST_VALUES 2

10 seconds for doing what? I have no idea!

kukeltje
Expert Member
Posts: 9605
Joined: 17 Jun 2010, 13:34
Location: Netherlands

10 Jul 2012, 19:47

I doubt this is all the logs that can be there. But if that is realy so, run te app in a profiler.

mask_hot
Posts: 34
Joined: 27 May 2011, 10:52

10 Jul 2012, 20:03

kukeltje wrote:I doubt this is all the logs that can be there. But if that is realy so, run te app in a profiler.
yep, I thought about this. I think I'll try this solution.

mask_hot
Posts: 34
Joined: 27 May 2011, 10:52

10 Jul 2012, 20:38

So I tried jprofiler and there are the results :

90,3% - 65 033 ms - 3 inv. com.sun.grizzly.util.AbstractThreadPool$Worker
90,2% - 64 943 ms - 1 inv. URL: /it-manager/hotel/
90,2% - 64 943 ms - 1 inv. com.ocpsoft.pretty.PrettyFilter
90,1% - 64 921 ms - 1 inv. javax.servlet.RequestDispatcher
90,1% - 64 920 ms - 1 inv. com.ocpsoft.pretty.PrettyFilter
90,1% - 64 920 ms - 1 inv. javax.servlet.FilterChain
90,0% - 64 840 ms - 125 inv. org.primefaces.component.datatable.DataTable
90,0% - 64 837 ms - 1 inv. org.primefaces.component.datatable.DataTableRenderer
90,0% - 64 836 ms - 2 inv. org.primefaces.component.datatable.DataHelper
72,4% - 52 111 ms - 2 748 845 inv. java.util.Map
72,3% - 52 099 ms - 1 718 027 inv. com.ocpsoft.pretty.faces.servlet.PrettyFacesWrappedRequest
66,3% - 47 786 ms - 5 154 081 inv. java.util.Map

2,3% - 1 644 ms - 1 718 027 inv. java.util.Collections
0,6% - 424 ms - 1 718 027 inv. java.util.TreeMap
0,0% - 3 434 µs - 1 718 027 inv. javax.servlet.http.HttpServletRequestWrapper

Post Reply

Return to “PrimeFaces”

  • Information
  • Who is online

    Users browsing this forum: No registered users and 52 guests