diff --git a/ganttzk/src/main/java/org/zkoss/ganttz/Planner.java b/ganttzk/src/main/java/org/zkoss/ganttz/Planner.java index 593deb7ac..8253560c3 100644 --- a/ganttzk/src/main/java/org/zkoss/ganttz/Planner.java +++ b/ganttzk/src/main/java/org/zkoss/ganttz/Planner.java @@ -33,6 +33,7 @@ import java.util.Map; import java.util.Map.Entry; import java.util.Set; +import org.apache.commons.logging.Log; import org.zkoss.ganttz.adapters.IDisabilityConfiguration; import org.zkoss.ganttz.adapters.IDomainAndBeansMapper; import org.zkoss.ganttz.adapters.PlannerConfiguration; @@ -52,7 +53,7 @@ import org.zkoss.ganttz.timetracker.zoom.ZoomLevel; import org.zkoss.ganttz.util.ComponentsFinder; import org.zkoss.ganttz.util.LongOperationFeedback; import org.zkoss.ganttz.util.LongOperationFeedback.ILongOperation; -import org.zkoss.ganttz.util.OnZKDesktopRegistry; +import org.zkoss.ganttz.util.ProfilingLogFactory; import org.zkoss.ganttz.util.WeakReferencedListeners; import org.zkoss.ganttz.util.WeakReferencedListeners.IListenerNotification; import org.zkoss.zk.au.AuRequest; @@ -76,6 +77,9 @@ import org.zkoss.zul.South; public class Planner extends HtmlMacroComponent { + private static final Log PROFILING_LOG = ProfilingLogFactory + .getLog(Planner.class); + public static boolean guessContainersExpandedByDefaultGivenPrintParameters( Map printParameters) { return guessContainersExpandedByDefault(convertToURLParameters(printParameters)); @@ -325,9 +329,12 @@ public class Planner extends HtmlMacroComponent { this.context = newContext; this.disabilityConfiguration = configuration; resettingPreviousComponentsToNull(); + long timeAddingData = System.currentTimeMillis(); newContext.add(configuration.getData()); + PROFILING_LOG.info("It took to add data: " + + (System.currentTimeMillis() - timeAddingData) + " ms"); + long timeSetupingAndAddingComponents = System.currentTimeMillis(); setupComponents(); - setAt("insertionPointLeftPanel", leftPane); leftPane.afterCompose(); setAt("insertionPointRightPanel", ganttPanel); @@ -366,6 +373,11 @@ public class Planner extends HtmlMacroComponent { this.visibleChart = configuration.isExpandPlanningViewCharts(); ((South) getFellow("graphics")).setOpen(this.visibleChart); + PROFILING_LOG + .info("it took doing the setup of components and adding them: " + + (System.currentTimeMillis() - timeSetupingAndAddingComponents) + + " ms"); + setAuService(new AuService(){ public boolean service(AuRequest request, boolean everError){ String command = request.getCommand(); diff --git a/ganttzk/src/main/java/org/zkoss/ganttz/util/ProfilingLogFactory.java b/ganttzk/src/main/java/org/zkoss/ganttz/util/ProfilingLogFactory.java new file mode 100644 index 000000000..284fa4919 --- /dev/null +++ b/ganttzk/src/main/java/org/zkoss/ganttz/util/ProfilingLogFactory.java @@ -0,0 +1,46 @@ +/* + * This file is part of NavalPlan + * + * Copyright (C) 2011 Igalia, S.L. + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU Affero General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Affero General Public License for more details. + * + * You should have received a copy of the GNU Affero General Public License + * along with this program. If not, see . + */ +package org.zkoss.ganttz.util; + +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; + +/** + * Equivalent to {@link LogFactory}. Use when logging profiling information. + * + * @author Óscar González Fernández + */ +public class ProfilingLogFactory { + + /** + * Use this method instead of {@link LogFactory#getLog(Class)} in order to + * get a {@link Log} that logs to a specific log for profiling. + * + * @param klass + * @return a normal instance of a {@link Log} object with starting with the + * profiling string. + */ + public static Log getLog(Class klass) { + return LogFactory.getLog("profiling." + klass.getName()); + } + + private ProfilingLogFactory() { + } + +} diff --git a/navalplanner-webapp/src/main/java/org/navalplanner/web/planner/order/OrderPlanningController.java b/navalplanner-webapp/src/main/java/org/navalplanner/web/planner/order/OrderPlanningController.java index 036df28fb..43c7a3a4f 100644 --- a/navalplanner-webapp/src/main/java/org/navalplanner/web/planner/order/OrderPlanningController.java +++ b/navalplanner-webapp/src/main/java/org/navalplanner/web/planner/order/OrderPlanningController.java @@ -32,6 +32,7 @@ import java.util.Map; import java.util.Map.Entry; import org.apache.commons.lang.Validate; +import org.apache.commons.logging.Log; import org.navalplanner.business.orders.entities.Order; import org.navalplanner.business.planner.entities.TaskElement; import org.navalplanner.web.common.ViewSwitcher; @@ -57,7 +58,7 @@ import org.zkoss.ganttz.extensions.IContextWithPlannerTask; import org.zkoss.ganttz.timetracker.zoom.ZoomLevel; import org.zkoss.ganttz.util.LongOperationFeedback; import org.zkoss.ganttz.util.LongOperationFeedback.ILongOperation; -import org.zkoss.ganttz.util.OnZKDesktopRegistry; +import org.zkoss.ganttz.util.ProfilingLogFactory; import org.zkoss.zk.ui.Executions; import org.zkoss.zk.ui.WrongValueException; import org.zkoss.zk.ui.util.Composer; @@ -73,6 +74,9 @@ import org.zkoss.zul.Vbox; @Scope(BeanDefinition.SCOPE_PROTOTYPE) public class OrderPlanningController implements Composer { + private static final Log PROFILING_LOG = ProfilingLogFactory + .getLog(OrderPlanningController.class); + @Autowired private ViewSwitcher viewSwitcher; @@ -186,10 +190,13 @@ public class OrderPlanningController implements Composer { private void updateConfiguration() { if (order != null) { + long time = System.currentTimeMillis(); model.setConfigurationToPlanner(planner, order, viewSwitcher, editTaskController, advanceAssignmentPlanningController, advanceConsolidationController, calendarAllocationController, additional); + PROFILING_LOG.info("setConfigurationToPlanner took: " + + (System.currentTimeMillis() - time) + " ms"); planner.updateSelectedZoomLevel(); showResorceAllocationIfIsNeeded(); } diff --git a/navalplanner-webapp/src/main/java/org/navalplanner/web/planner/order/OrderPlanningModel.java b/navalplanner-webapp/src/main/java/org/navalplanner/web/planner/order/OrderPlanningModel.java index 5c826b14a..7d415fec6 100644 --- a/navalplanner-webapp/src/main/java/org/navalplanner/web/planner/order/OrderPlanningModel.java +++ b/navalplanner-webapp/src/main/java/org/navalplanner/web/planner/order/OrderPlanningModel.java @@ -139,6 +139,7 @@ import org.zkoss.ganttz.timetracker.zoom.IZoomLevelChangedListener; import org.zkoss.ganttz.timetracker.zoom.SeveralModificators; import org.zkoss.ganttz.timetracker.zoom.ZoomLevel; import org.zkoss.ganttz.util.Interval; +import org.zkoss.ganttz.util.ProfilingLogFactory; import org.zkoss.zk.ui.Executions; import org.zkoss.zk.ui.WrongValueException; import org.zkoss.zk.ui.event.Event; @@ -175,6 +176,9 @@ public abstract class OrderPlanningModel implements IOrderPlanningModel { private static final Log LOG = LogFactory.getLog(OrderPlanningModel.class); + private static final Log PROFILING_LOG = ProfilingLogFactory + .getLog(OrderPlanningModel.class); + public static > T loadRequiredDataFor( T resources) { for (Resource each : resources) { @@ -362,9 +366,12 @@ public abstract class OrderPlanningModel implements IOrderPlanningModel { AdvanceConsolidationController advanceConsolidationController, CalendarAllocationController calendarAllocationController, List> additional) { + long time = System.currentTimeMillis(); currentScenario = scenarioManager.getCurrent(); orderReloaded = reload(order); PlannerConfiguration configuration = createConfiguration(planner, orderReloaded); + PROFILING_LOG.info("load data and create configuration took: " + + (System.currentTimeMillis() - time) + " ms"); User user; try { user = this.userDAO.findByLoginName(SecurityUtils @@ -374,7 +381,6 @@ public abstract class OrderPlanningModel implements IOrderPlanningModel { } configuration.setExpandPlanningViewCharts(user .isExpandOrderPlanningViewCharts()); - addAdditional(additional, configuration); ZoomLevel defaultZoomLevel = OrderPlanningModel @@ -419,8 +425,11 @@ public abstract class OrderPlanningModel implements IOrderPlanningModel { configuration.setChartComponent(chartComponent); configureModificators(orderReloaded, configuration); + long setConfigurationTime = System.currentTimeMillis(); planner.setConfiguration(configuration); - + PROFILING_LOG.info("setConfiguration on planner took: " + + (System.currentTimeMillis() - setConfigurationTime) + " ms"); + long preparingChartsAndMisc = System.currentTimeMillis(); // Prepare tabpanels Tabpanels chartTabpanels = new Tabpanels(); @@ -447,10 +456,17 @@ public abstract class OrderPlanningModel implements IOrderPlanningModel { planner, changeHooker); setupOverallProgress(planner, changeHooker); setupAdvanceAssignmentPlanningController(planner, advanceAssignmentPlanningController); + PROFILING_LOG + .info("preparing charts and miscellaneous took: " + + (System.currentTimeMillis() - preparingChartsAndMisc) + + " ms"); planner.addGraphChangeListenersFromConfiguration(configuration); + long overalProgressContentTime = System.currentTimeMillis(); overallProgressContent = new OverAllProgressContent(overallProgressTab); overallProgressContent.updateAndRefresh(); + PROFILING_LOG.info("overalProgressContent took: " + + (System.currentTimeMillis() - overalProgressContentTime)); } private void setupAdvanceAssignmentPlanningController(final Planner planner, diff --git a/navalplanner-webapp/src/main/resources/log4j.xml b/navalplanner-webapp/src/main/resources/log4j.xml index 715b49644..7dc4628d6 100644 --- a/navalplanner-webapp/src/main/resources/log4j.xml +++ b/navalplanner-webapp/src/main/resources/log4j.xml @@ -31,6 +31,19 @@ + + + + + + + + + + + + + @@ -38,8 +51,19 @@ + + + + + + + + + + + - + \ No newline at end of file