Author: bpoussin Date: 2014-07-08 19:24:51 +0200 (Tue, 08 Jul 2014) New Revision: 4031 Url: http://forge.codelutin.com/projects/isis-fish/repository/revisions/4031 Log: - use nuiton-profiling to statistics call instead of Trace class - add method on StrategieMonthInfo to get all Metier with proportion Removed: trunk/src/main/java/fr/ifremer/isisfish/util/Trace.java Modified: trunk/pom.xml trunk/src/main/java/fr/ifremer/isisfish/aspect/TraceAspect.java trunk/src/main/java/fr/ifremer/isisfish/entities/StrategyMonthInfoImpl.java trunk/src/main/java/fr/ifremer/isisfish/simulator/SimulationContext.java trunk/src/main/java/fr/ifremer/isisfish/simulator/launcher/InProcessSimulatorLauncher.java trunk/src/main/java/fr/ifremer/isisfish/util/IsisCache.java trunk/src/main/java/fr/ifremer/isisfish/util/IsisCacheBackendOnReferenceMap.java trunk/src/main/xmi/isis-fish.zargo Modified: trunk/pom.xml =================================================================== --- trunk/pom.xml 2014-07-07 16:53:07 UTC (rev 4030) +++ trunk/pom.xml 2014-07-08 17:24:51 UTC (rev 4031) @@ -79,6 +79,13 @@ </dependency> <dependency> + <groupId>org.nuiton</groupId> + <artifactId>nuiton-profiling</artifactId> + <version>2.7.2-SNAPSHOT</version> + <scope>compile</scope> + </dependency> + + <dependency> <groupId>org.nuiton.matrix</groupId> <artifactId>nuiton-matrix</artifactId> <version>2.4.2-SNAPSHOT</version> Modified: trunk/src/main/java/fr/ifremer/isisfish/aspect/TraceAspect.java =================================================================== --- trunk/src/main/java/fr/ifremer/isisfish/aspect/TraceAspect.java 2014-07-07 16:53:07 UTC (rev 4030) +++ trunk/src/main/java/fr/ifremer/isisfish/aspect/TraceAspect.java 2014-07-08 17:24:51 UTC (rev 4031) @@ -35,7 +35,8 @@ import org.aspectj.lang.reflect.MethodSignature; import fr.ifremer.isisfish.simulator.SimulationContext; -import fr.ifremer.isisfish.util.Trace; +import org.nuiton.profiling.Trace; +//import fr.ifremer.isisfish.util.Trace; /** * Permet de tracer les appels aux methodes utilisateur ainsi que l'execution @@ -79,9 +80,11 @@ + " || execution(* simulators..*(..))" + " || execution(* rules..*(..)) " + " || execution(* simulationplans..*(..)) " - + " || execution(* formules..*(..))") +// + " || execution(* formules..*(..))" + ) public void traceBeforeExecute(JoinPoint jp) { - getTrace().traceBefore(); + Method method = ((MethodSignature) jp.getSignature()).getMethod(); + getTrace().enter(method); } @AfterThrowing(throwing = "ex", @@ -89,7 +92,8 @@ + " || execution(* simulators..*(..))" + " || execution(* rules..*(..)) " + " || execution(* simulationplans..*(..)) " - + " || execution(* formules..*(..))") +// + " || execution(* formules..*(..))" + ) public void traceAfterThrowingExecute(JoinPoint jp, Exception ex) { // si une exeption est leve, il faut faire la meme chose traceAfterExecute(jp); @@ -99,9 +103,10 @@ + " || execution(* simulators..*(..))" + " || execution(* rules..*(..)) " + " || execution(* simulationplans..*(..)) " - + " || execution(* formules..*(..))") +// + " || execution(* formules..*(..))" + ) public void traceAfterExecute(JoinPoint jp) { Method method = ((MethodSignature) jp.getSignature()).getMethod(); - getTrace().traceAfterCall(method); + getTrace().exit(method); } } Modified: trunk/src/main/java/fr/ifremer/isisfish/entities/StrategyMonthInfoImpl.java =================================================================== --- trunk/src/main/java/fr/ifremer/isisfish/entities/StrategyMonthInfoImpl.java 2014-07-07 16:53:07 UTC (rev 4030) +++ trunk/src/main/java/fr/ifremer/isisfish/entities/StrategyMonthInfoImpl.java 2014-07-08 17:24:51 UTC (rev 4031) @@ -39,6 +39,7 @@ import fr.ifremer.isisfish.IsisFishRuntimeException; import fr.ifremer.isisfish.datastore.RegionStorage; import fr.ifremer.isisfish.datastore.StorageException; +import org.nuiton.math.matrix.MatrixIterator; /** * StrategyMonthInfoImpl. @@ -69,6 +70,16 @@ } } + @Override + public List<Metier> getMetierWithProportion() { + MatrixND mat = super.getProportionMetier(); + List<Metier> result = new ArrayList<Metier>(mat.getDim(0)); + for (MatrixIterator i=mat.iteratorNotZero(); i.next();) { + result.add((Metier)i.getSemanticsCoordinates()[0]); + } + return result; + } + public double getProportionMetier(Metier metier) { double result = 0; // on prend le super car ca ne sert a rien de mettre a jour, Modified: trunk/src/main/java/fr/ifremer/isisfish/simulator/SimulationContext.java =================================================================== --- trunk/src/main/java/fr/ifremer/isisfish/simulator/SimulationContext.java 2014-07-07 16:53:07 UTC (rev 4030) +++ trunk/src/main/java/fr/ifremer/isisfish/simulator/SimulationContext.java 2014-07-08 17:24:51 UTC (rev 4031) @@ -42,10 +42,11 @@ import fr.ifremer.isisfish.simulator.sensitivity.SensitivityUtils; import fr.ifremer.isisfish.types.TimeStep; import fr.ifremer.isisfish.util.IsisCache; -import fr.ifremer.isisfish.util.Trace; +//import fr.ifremer.isisfish.util.Trace; import org.nuiton.config.ApplicationConfig; import org.nuiton.config.OverwriteApplicationConfig; import org.nuiton.math.matrix.MatrixFactory; +import org.nuiton.profiling.Trace; /** * Keep all information on one simulation. @@ -140,7 +141,7 @@ SimulationContext current = get(); current.getCache().clear(); current.cache = null; - current.getTrace().clear(); + current.getTrace().clearStatistics(); current.trace = null; current.values.clear(); current.classLoader = null; @@ -248,7 +249,7 @@ public Trace getTrace() { if (trace == null) { - trace = new Trace(); + trace = new Trace(false, false); } return trace; } Modified: trunk/src/main/java/fr/ifremer/isisfish/simulator/launcher/InProcessSimulatorLauncher.java =================================================================== --- trunk/src/main/java/fr/ifremer/isisfish/simulator/launcher/InProcessSimulatorLauncher.java 2014-07-07 16:53:07 UTC (rev 4030) +++ trunk/src/main/java/fr/ifremer/isisfish/simulator/launcher/InProcessSimulatorLauncher.java 2014-07-08 17:24:51 UTC (rev 4031) @@ -511,7 +511,7 @@ (end - start) / 1000000, "s'.'S")); SimulationParameter param = simulation.getParameter(); if (param.getUseStatistic()) { - String trace = context.getTrace().printStatisticAndClear(); + String trace = context.getTrace().getStatisticsCSV(); simulation.getInformation().setStatistic(trace); } if (param.getUseCache()) { Modified: trunk/src/main/java/fr/ifremer/isisfish/util/IsisCache.java =================================================================== --- trunk/src/main/java/fr/ifremer/isisfish/util/IsisCache.java 2014-07-07 16:53:07 UTC (rev 4030) +++ trunk/src/main/java/fr/ifremer/isisfish/util/IsisCache.java 2014-07-08 17:24:51 UTC (rev 4031) @@ -74,16 +74,16 @@ this.cacheBackend = cacheBackend; } - /** - * Return trace object from context. - * - * @return trace object from context - */ - protected Trace getTrace() { - SimulationContext context = SimulationContext.get(); - Trace result = context.getTrace(); - return result; - } +// /** +// * Return trace object from context. +// * +// * @return trace object from context +// */ +// protected org.nuiton.profiling.Trace getTrace() { +// SimulationContext context = SimulationContext.get(); +// org.nuiton.profiling.Trace result = context.getTrace(); +// return result; +// } /** * Recupere pour un pas de temps donnes une valeur calcule pour une cle. Modified: trunk/src/main/java/fr/ifremer/isisfish/util/IsisCacheBackendOnReferenceMap.java =================================================================== --- trunk/src/main/java/fr/ifremer/isisfish/util/IsisCacheBackendOnReferenceMap.java 2014-07-07 16:53:07 UTC (rev 4030) +++ trunk/src/main/java/fr/ifremer/isisfish/util/IsisCacheBackendOnReferenceMap.java 2014-07-08 17:24:51 UTC (rev 4031) @@ -84,16 +84,16 @@ public IsisCacheBackendOnReferenceMap() { } - /** - * Return trace object from context. - * - * @return trace object from context - */ - protected Trace getTrace() { - SimulationContext context = SimulationContext.get(); - Trace result = context.getTrace(); - return result; - } +// /** +// * Return trace object from context. +// * +// * @return trace object from context +// */ +// protected Trace getTrace() { +// SimulationContext context = SimulationContext.get(); +// Trace result = context.getTrace(); +// return result; +// } protected Map getCacheTimeStep(TimeStep step) { Object key = step; Deleted: trunk/src/main/java/fr/ifremer/isisfish/util/Trace.java =================================================================== --- trunk/src/main/java/fr/ifremer/isisfish/util/Trace.java 2014-07-07 16:53:07 UTC (rev 4030) +++ trunk/src/main/java/fr/ifremer/isisfish/util/Trace.java 2014-07-08 17:24:51 UTC (rev 4031) @@ -1,213 +0,0 @@ -/* - * #%L - * IsisFish - * - * $Id$ - * $HeadURL$ - * %% - * Copyright (C) 2002 - 2010 Ifremer, Code Lutin, Benjamin Poussin - * %% - * This program is free software: you can redistribute it and/or modify - * it under the terms of the GNU 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 General Public License for more details. - * - * You should have received a copy of the GNU General Public - * License along with this program. If not, see - * <http://www.gnu.org/licenses/gpl-3.0.html>. - * #L% - */ - -package fr.ifremer.isisfish.util; - -import java.util.LinkedHashMap; -import java.util.Map; -import java.util.Stack; -import org.apache.commons.lang3.time.DurationFormatUtils; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; - -/** - * Permet de tracer les appels aux methodes utilisateur ainsi que l'execution - * a ces methodes. La difference entre les deux est lors de l'utilisation du - * cache les appels seront superieur a l'execution car certaine valeur seront - * reutilisé dans le cache. - * - * @author poussin - * @version $Revision$ - * - * Last update: $Date$ - * by : $Author$ - */ -public class Trace { - - /** to use log facility, just put in your code: log.info(\"...\"); */ - static private Log log = LogFactory.getLog(Trace.class); - - /** nombre d'appel Cache inclus*/ - final static public int STAT_CALL = 0; - /** nombre d'appel reel qui a fait le calcul*/ - final static public int STAT_COMPUTATION = 1; - /** nombre d'appel vers une autre e depuis cette methode */ - final static public int STAT_CALL_NEST_METHOD = 2; - /** temps mini d'execution de cette methode (sans le temps des autres methodes) */ - final static public int STAT_TIME_MIN = 3; - /** temps max d'execution de cette methode (sans le temps des autres methodes) */ - final static public int STAT_TIME_MAX = 4; - /** temps total d'execution de cette methode (sans le temps des autres methodes) */ - final static public int STAT_TIME_TOTAL = 5; - /** temps total d'execution de cette methode (avec le temps des autres methodes) */ - final static public int STAT_TIME_TOTAL_NEST_METHOD = 6; - - /** nombre d'appel vers une autre e depuis cette methode */ - final static private int STACK_CALL_NEST_METHOD = 0; - /** heure de depart de l'appel a la methode (sans le temps des autres methodes) */ - final static private int STACK_TIME_START = 1; - /** heure de depart de l'appel a la methode (avec le temps des autres methodes) */ - final static private int STACK_TIME_START_NEST_METHOD = 2; - - /** array : [call's numbers, call do, min time, max time, total time, total time with child]*/ - protected Map<String, long[]> statistics = new LinkedHashMap<String, long[]>(); - - /** array : [nest e call, start time, start time with child] */ - protected Stack<long[]> callStack = new Stack<long[]>(); - - public Trace() { - } - - public long[] getStatistics(Object e) { - String key = String.valueOf(e); - long [] result = statistics.get(key); - if (result == null) { - result = new long[]{0, 0, 0, 0, 0, 0, 0}; - statistics.put(key, result); - } - return result; - } - - /** - * Clear current value statistics (all is reset) - */ - public void clear() { - statistics.clear(); - } - - public void traceBefore () { - // ajout dans le stack - long current = System.nanoTime(); - long [] stackItem = new long[]{0, current, current}; - callStack.push(stackItem); - } - - public void traceAfterCall(Object e) { - traceAfter(e, false); - } - public void traceAfterComputation(Object e) { - traceAfter(e, true); - } - - protected void traceAfter(Object e, boolean computation) { - long current = System.nanoTime(); - - if (callStack.isEmpty()) { - log.warn("Empty stack in after for " + e); - } else { - long [] stackItem = callStack.pop(); - long timeSpent = current - stackItem[STACK_TIME_START]; - long timeSpentNestMethod = current - stackItem[STACK_TIME_START_NEST_METHOD]; - - long [] stat = getStatistics(e); - if (computation) { - stat[STAT_COMPUTATION]++; // add +1 to computation number - } else { - // on incremente pas tout le temps STAT_CALL, car le plus - // souvent lors de l'utilisation de l'objet Trace dans un cache - // on a deja compte l'appel et reappelle lui meme computation - // ce qui ferait 2 appel alors qu'il n'y en a qu'un en realite - stat[STAT_CALL]++; // add +1 to call number - } - stat[STAT_CALL_NEST_METHOD] += stackItem[STACK_CALL_NEST_METHOD]; - stat[STAT_TIME_TOTAL] += timeSpent; - stat[STAT_TIME_TOTAL_NEST_METHOD] += timeSpentNestMethod; - if (stat[STAT_TIME_MIN] > timeSpent) { - stat[STAT_TIME_MIN] = timeSpent; - } - if (stat[STAT_TIME_MAX] < timeSpent) { - stat[STAT_TIME_MAX] = timeSpent; - } - - if (!callStack.isEmpty()) { - long [] parent = callStack.peek(); - parent[STACK_CALL_NEST_METHOD]++; // add +1 to call number nest e - parent[STACK_TIME_START] += timeSpentNestMethod; // remove to time all time spent in nest e (yes + to remove :) - } - } - - // ajouter le delta de temps dans le temps passé dans la méthod - - // il faud garder le temps passé dans l'appel d'autre methode de la stack - // --> A - // ========= - // --> B - // <-- B - // ========= - // --> C - // --> D - // <-- D - // <-- C - // ========= - // <-- A - - // le temps reellement passé dans A est representé par les ===== - } - - public String printStatisticAndClear() { - long call = 0; - long computation = 0; - StringBuffer result = new StringBuffer(); - result.append("--- " + " Statistics ---\n"); - for (String e : statistics.keySet()) { - long[] stat = getStatistics(e); - - // fix / by zero - // if Cache aspect has not been selected - if (stat[STAT_COMPUTATION] == 0) { - stat[STAT_COMPUTATION] = stat[STAT_CALL]; - } - - long meanTime = stat[STAT_TIME_TOTAL] / stat[STAT_COMPUTATION]; - call += stat[STAT_CALL]; - computation += stat[STAT_COMPUTATION]; - result.append( - e + - " call: " + stat[STAT_CALL] + - " computation: " + stat[STAT_COMPUTATION] + - // usage du cache - "(" + (100*stat[STAT_COMPUTATION]/stat[STAT_CALL]) + "%)" + - // Time is in nano not millis, we must divide by 1000000 - " min: " + DurationFormatUtils.formatDuration(stat[STAT_TIME_MIN] / 1000000, "s'.'S") + - " mean: " + DurationFormatUtils.formatDuration(meanTime / 1000000, "s'.'S") + - " max: " + DurationFormatUtils.formatDuration(stat[STAT_TIME_MAX] / 1000000, "s'.'S") + - " total: " + DurationFormatUtils.formatDuration(stat[STAT_TIME_TOTAL] / 1000000, "s'.'S") + - " call_nest: " + stat[STAT_CALL_NEST_METHOD] + - " total_with_nest: " + DurationFormatUtils.formatDuration(stat[STAT_TIME_TOTAL_NEST_METHOD] / 1000000, "s'.'S") + - "\n"); - } - result.append("--------------------\n"); - result.append("Total call: " + call + "\n"); - result.append("Total computation: " + computation + "\n"); - result.append("Cache usage: " + (100 * (call-computation) / (call+1/*+1 pour la / par 0 */) ) + "%" + "\n"); - result.append("--------------------\n"); - callStack.clear(); - statistics.clear(); - - System.out.println(result.toString()); - return result.toString(); - } - -} Modified: trunk/src/main/xmi/isis-fish.zargo =================================================================== (Binary files differ)