123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710 |
- /*
- * Copyright 2000-2016 Vaadin Ltd.
- *
- * Licensed under the Apache License, Version 2.0 (the "License"); you may not
- * use this file except in compliance with the License. You may obtain a copy of
- * the License at
- *
- * http://www.apache.org/licenses/LICENSE-2.0
- *
- * Unless required by applicable law or agreed to in writing, software
- * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
- * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
- * License for the specific language governing permissions and limitations under
- * the License.
- */
-
- package com.vaadin.client;
-
- import java.util.ArrayList;
- import java.util.Collection;
- import java.util.Collections;
- import java.util.Comparator;
- import java.util.HashMap;
- import java.util.HashSet;
- import java.util.LinkedHashMap;
- import java.util.LinkedList;
- import java.util.List;
- import java.util.Map;
- import java.util.Set;
- import java.util.logging.Logger;
-
- import com.google.gwt.core.client.Duration;
- import com.google.gwt.core.client.GWT;
- import com.google.gwt.core.client.JavaScriptObject;
- import com.google.gwt.core.client.JsArray;
-
- /**
- * Lightweight profiling tool that can be used to collect profiling data with
- * zero overhead unless enabled. To enable profiling, add
- * <code><set-property name="vaadin.profiler" value="true" /></code> to
- * your .gwt.xml file.
- *
- * @author Vaadin Ltd
- * @since 7.0.0
- */
- public class Profiler {
-
- private static RelativeTimeSupplier RELATIVE_TIME_SUPPLIER;
-
- private static final String EVT_GROUP = "VaadinProfiler";
-
- private static ProfilerResultConsumer consumer;
-
- /**
- * Class to include using deferred binding to enable the profiling.
- *
- * @author Vaadin Ltd
- * @since 7.0.0
- */
- public static class EnabledProfiler extends Profiler {
-
- @Override
- protected boolean isImplEnabled() {
- return true;
- }
- }
-
- /**
- * Interface for getting data from the {@link Profiler}.
- * <p>
- * <b>Warning!</b> This interface is most likely to change in the future
- *
- * @since 7.1
- * @author Vaadin Ltd
- */
- public interface ProfilerResultConsumer {
- public void addProfilerData(Node rootNode, List<Node> totals);
-
- public void addBootstrapData(LinkedHashMap<String, Double> timings);
- }
-
- /**
- * A hierarchical representation of the time spent running a named block of
- * code.
- * <p>
- * <b>Warning!</b> This class is most likely to change in the future and is
- * therefore defined in this class in an internal package instead of
- * Profiler where it might seem more logical.
- */
- public static class Node {
- private final String name;
- private final LinkedHashMap<String, Node> children = new LinkedHashMap<>();
- private double time = 0;
- private int count = 0;
- private double enterTime = 0;
- private double minTime = 1000000000;
- private double maxTime = 0;
-
- /**
- * Create a new node with the given name.
- *
- * @param name
- */
- public Node(String name) {
- this.name = name;
- }
-
- /**
- * Gets the name of the node.
- *
- * @return the name of the node
- */
- public String getName() {
- return name;
- }
-
- /**
- * Creates a new child node or retrieves and existing child and updates
- * its total time and hit count.
- *
- * @param name
- * the name of the child
- * @param timestamp
- * the timestamp for when the node is entered
- * @return the child node object
- */
- public Node enterChild(String name, double timestamp) {
- Node child = children.get(name);
- if (child == null) {
- child = new Node(name);
- children.put(name, child);
- }
- child.enterTime = timestamp;
- child.count++;
- return child;
- }
-
- /**
- * Gets the total time spent in this node, including time spent in sub
- * nodes.
- *
- * @return the total time spent, in milliseconds
- */
- public double getTimeSpent() {
- return time;
- }
-
- /**
- * Gets the minimum time spent for one invocation of this node,
- * including time spent in sub nodes.
- *
- * @return the time spent for the fastest invocation, in milliseconds
- */
- public double getMinTimeSpent() {
- return minTime;
- }
-
- /**
- * Gets the maximum time spent for one invocation of this node,
- * including time spent in sub nodes.
- *
- * @return the time spent for the slowest invocation, in milliseconds
- */
- public double getMaxTimeSpent() {
- return maxTime;
- }
-
- /**
- * Gets the number of times this node has been entered.
- *
- * @return the number of times the node has been entered
- */
- public int getCount() {
- return count;
- }
-
- /**
- * Gets the total time spent in this node, excluding time spent in sub
- * nodes.
- *
- * @return the total time spent, in milliseconds
- */
- public double getOwnTime() {
- double time = getTimeSpent();
- for (Node node : children.values()) {
- time -= node.getTimeSpent();
- }
- return time;
- }
-
- /**
- * Gets the child nodes of this node.
- *
- * @return a collection of child nodes
- */
- public Collection<Node> getChildren() {
- return Collections.unmodifiableCollection(children.values());
- }
-
- @Override
- public String toString() {
- return getStringRepresentation("");
- }
-
- public String getStringRepresentation(String prefix) {
- if (getName() == null) {
- return "";
- }
- String msg = prefix + " " + getName() + " in "
- + roundToSignificantFigures(getTimeSpent()) + " ms.";
- if (getCount() > 1) {
- msg += " Invoked " + getCount() + " times ("
- + roundToSignificantFigures(getTimeSpent() / getCount())
- + " ms per time, min "
- + roundToSignificantFigures(getMinTimeSpent())
- + " ms, max "
- + roundToSignificantFigures(getMaxTimeSpent())
- + " ms).";
- }
- if (!children.isEmpty()) {
- double ownTime = getOwnTime();
- msg += " " + roundToSignificantFigures(ownTime)
- + " ms spent in own code";
- if (getCount() > 1) {
- msg += " ("
- + roundToSignificantFigures(ownTime / getCount())
- + " ms per time)";
- }
- msg += '.';
- }
- return msg;
- }
-
- private static double roundToSignificantFigures(double num) {
- // Number of significant digits
- int n = 3;
- if (num == 0) {
- return 0;
- }
-
- final double d = Math.ceil(Math.log10(num < 0 ? -num : num));
- final int power = n - (int) d;
-
- final double magnitude = Math.pow(10, power);
- final long shifted = Math.round(num * magnitude);
- return shifted / magnitude;
- }
-
- public void sumUpTotals(Map<String, Node> totals) {
- String name = getName();
- if (name != null) {
- Node totalNode = totals.get(name);
- if (totalNode == null) {
- totalNode = new Node(name);
- totals.put(name, totalNode);
- }
-
- totalNode.time += getOwnTime();
- totalNode.count += getCount();
- totalNode.minTime = roundToSignificantFigures(
- Math.min(totalNode.minTime, getMinTimeSpent()));
- totalNode.maxTime = roundToSignificantFigures(
- Math.max(totalNode.maxTime, getMaxTimeSpent()));
- }
- for (Node node : children.values()) {
- node.sumUpTotals(totals);
- }
- }
-
- /**
- * @param timestamp
- */
- public void leave(double timestamp) {
- double elapsed = (timestamp - enterTime);
- time += elapsed;
- enterTime = 0;
- if (elapsed < minTime) {
- minTime = elapsed;
- }
- if (elapsed > maxTime) {
- maxTime = elapsed;
- }
- }
- }
-
- private static final class GwtStatsEvent extends JavaScriptObject {
- protected GwtStatsEvent() {
- // JSO constructor
- }
-
- private native String getEvtGroup()
- /*-{
- return this.EVT_GROUP;
- }-*/;
-
- private native double getMillis()
- /*-{
- return this.millis;
- }-*/;
-
- private native String getSubSystem()
- /*-{
- return this.subSystem;
- }-*/;
-
- private native String getType()
- /*-{
- return this.type;
- }-*/;
-
- private native String getModuleName()
- /*-{
- return this.moduleName;
- }-*/;
-
- private native double getRelativeMillis()
- /*-{
- return this.relativeMillis;
- }-*/;
-
- private native boolean isExtendedEvent()
- /*-{
- return 'relativeMillis' in this;
- }-*/;
-
- public final String getEventName() {
- String group = getEvtGroup();
- if (EVT_GROUP.equals(group)) {
- return getSubSystem();
- } else {
- return group + "." + getSubSystem();
- }
- }
- }
-
- /**
- * Checks whether the profiling gathering is enabled.
- *
- * @return <code>true</code> if the profiling is enabled, else
- * <code>false</code>
- */
- public static boolean isEnabled() {
- // This will be fully inlined by the compiler
- Profiler create = GWT.create(Profiler.class);
- return create.isImplEnabled();
- }
-
- /**
- * Enters a named block. There should always be a matching invocation of
- * {@link #leave(String)} when leaving the block. Calls to this method will
- * be removed by the compiler unless profiling is enabled.
- *
- * @param name
- * the name of the entered block
- */
- public static void enter(String name) {
- if (isEnabled()) {
- logGwtEvent(name, "begin");
- }
- }
-
- /**
- * Leaves a named block. There should always be a matching invocation of
- * {@link #enter(String)} when entering the block. Calls to this method will
- * be removed by the compiler unless profiling is enabled.
- *
- * @param name
- * the name of the left block
- */
- public static void leave(String name) {
- if (isEnabled()) {
- logGwtEvent(name, "end");
- }
- }
-
- /**
- * Returns time relative to the particular page load time. The value should
- * not be used directly but rather difference between two values returned by
- * this method should be used to compare measurements.
- *
- * @since 7.6
- */
- public static double getRelativeTimeMillis() {
- return RELATIVE_TIME_SUPPLIER.getRelativeTime();
- }
-
- private static final native void logGwtEvent(String name, String type)
- /*-{
- $wnd.__gwtStatsEvent({
- evtGroup: @com.vaadin.client.Profiler::EVT_GROUP,
- moduleName: @com.google.gwt.core.client.GWT::getModuleName()(),
- millis: (new Date).getTime(),
- sessionId: undefined,
- subSystem: name,
- type: type,
- relativeMillis: @com.vaadin.client.Profiler::getRelativeTimeMillis()()
- });
- }-*/;
-
- /**
- * Resets the collected profiler data. Calls to this method will be removed
- * by the compiler unless profiling is enabled.
- */
- public static void reset() {
- if (isEnabled()) {
- /*
- * Old implementations might call reset for initialization, so
- * ensure it is initialized here as well. Initialization has no side
- * effects if already done.
- */
- initialize();
-
- clearEventsList();
- }
- }
-
- /**
- * Initializes the profiler. This should be done before calling any other
- * function in this class. Failing to do so might cause undesired behavior.
- * This method has no side effects if the initialization has already been
- * done.
- * <p>
- * Please note that this method should be called even if the profiler is not
- * enabled because it will then remove a logger function that might have
- * been included in the HTML page and that would leak memory unless removed.
- * </p>
- *
- * @since 7.0.2
- */
- public static void initialize() {
- if (hasHighPrecisionTime()) {
- RELATIVE_TIME_SUPPLIER = new HighResolutionTimeSupplier();
- } else {
- RELATIVE_TIME_SUPPLIER = new DefaultRelativeTimeSupplier();
- }
- if (isEnabled()) {
- ensureLogger();
- } else {
- ensureNoLogger();
- }
- }
-
- /**
- * Outputs the gathered profiling data to the debug console.
- */
- public static void logTimings() {
- if (!isEnabled()) {
- getLogger().warning(
- "Profiler is not enabled, no data has been collected.");
- return;
- }
-
- LinkedList<Node> stack = new LinkedList<>();
- Node rootNode = new Node(null);
- stack.add(rootNode);
- JsArray<GwtStatsEvent> gwtStatsEvents = getGwtStatsEvents();
- if (gwtStatsEvents.length() == 0) {
- getLogger().warning(
- "No profiling events recorded, this might happen if another __gwtStatsEvent handler is installed.");
- return;
- }
-
- Set<Node> extendedTimeNodes = new HashSet<>();
- for (int i = 0; i < gwtStatsEvents.length(); i++) {
- GwtStatsEvent gwtStatsEvent = gwtStatsEvents.get(i);
- if (!EVT_GROUP.equals(gwtStatsEvent.getEvtGroup())) {
- // Only log our own events to avoid problems with events which
- // are not of type start+end
- continue;
- }
- String eventName = gwtStatsEvent.getEventName();
-
- String type = gwtStatsEvent.getType();
- boolean isExtendedEvent = gwtStatsEvent.isExtendedEvent();
- boolean isBeginEvent = "begin".equals(type);
-
- Node stackTop = stack.getLast();
- boolean inEvent = eventName.equals(stackTop.getName())
- && !isBeginEvent;
-
- if (!inEvent && stack.size() >= 2
- && eventName.equals(stack.get(stack.size() - 2).getName())
- && !isBeginEvent) {
- // back out of sub event
- if (extendedTimeNodes.contains(stackTop) && isExtendedEvent) {
- stackTop.leave(gwtStatsEvent.getRelativeMillis());
- } else {
- stackTop.leave(gwtStatsEvent.getMillis());
- }
- stack.removeLast();
- stackTop = stack.getLast();
-
- inEvent = true;
- }
-
- if (type.equals("end")) {
- if (!inEvent) {
- getLogger().severe("Got end event for " + eventName
- + " but is currently in " + stackTop.getName());
- return;
- }
- Node previousStackTop = stack.removeLast();
- if (extendedTimeNodes.contains(previousStackTop)) {
- previousStackTop.leave(gwtStatsEvent.getRelativeMillis());
- } else {
- previousStackTop.leave(gwtStatsEvent.getMillis());
- }
- } else {
- double millis = isExtendedEvent
- ? gwtStatsEvent.getRelativeMillis()
- : gwtStatsEvent.getMillis();
- if (!inEvent) {
- stackTop = stackTop.enterChild(eventName, millis);
- stack.add(stackTop);
- if (isExtendedEvent) {
- extendedTimeNodes.add(stackTop);
- }
- }
- if (!isBeginEvent) {
- // Create sub event
- Node subNode = stackTop.enterChild(eventName + "." + type,
- millis);
- if (isExtendedEvent) {
- extendedTimeNodes.add(subNode);
- }
- stack.add(subNode);
- }
- }
- }
-
- if (stack.size() != 1) {
- getLogger().warning("Not all nodes are left, the last node is "
- + stack.getLast().getName());
- return;
- }
-
- Map<String, Node> totals = new HashMap<>();
- rootNode.sumUpTotals(totals);
-
- List<Node> totalList = new ArrayList<>(totals.values());
- Collections.sort(totalList, new Comparator<Node>() {
- @Override
- public int compare(Node o1, Node o2) {
- return (int) (o2.getTimeSpent() - o1.getTimeSpent());
- }
- });
-
- if (getConsumer() != null) {
- getConsumer().addProfilerData(stack.getFirst(), totalList);
- }
- }
-
- /**
- * Overridden in {@link EnabledProfiler} to make {@link #isEnabled()} return
- * true if GWT.create returns that class.
- *
- * @return <code>true</code> if the profiling is enabled, else
- * <code>false</code>
- */
- protected boolean isImplEnabled() {
- return false;
- }
-
- /**
- * Outputs the time passed since various events recored in
- * performance.timing if supported by the browser.
- */
- public static void logBootstrapTimings() {
- if (isEnabled()) {
- double now = Duration.currentTimeMillis();
-
- String[] keys = { "navigationStart", "unloadEventStart",
- "unloadEventEnd", "redirectStart", "redirectEnd",
- "fetchStart", "domainLookupStart", "domainLookupEnd",
- "connectStart", "connectEnd", "requestStart",
- "responseStart", "responseEnd", "domLoading",
- "domInteractive", "domContentLoadedEventStart",
- "domContentLoadedEventEnd", "domComplete", "loadEventStart",
- "loadEventEnd" };
-
- LinkedHashMap<String, Double> timings = new LinkedHashMap<>();
-
- for (String key : keys) {
- double value = getPerformanceTiming(key);
- if (value == 0) {
- // Ignore missing value
- continue;
- }
- timings.put(key, Double.valueOf(now - value));
- }
-
- if (timings.isEmpty()) {
- getLogger().info(
- "Bootstrap timings not supported, please ensure your browser supports performance.timing");
- return;
- }
-
- if (getConsumer() != null) {
- getConsumer().addBootstrapData(timings);
- }
- }
- }
-
- private static final native double getPerformanceTiming(String name)
- /*-{
- if ($wnd.performance && $wnd.performance.timing && $wnd.performance.timing[name]) {
- return $wnd.performance.timing[name];
- } else {
- return 0;
- }
- }-*/;
-
- private static native JsArray<GwtStatsEvent> getGwtStatsEvents()
- /*-{
- return $wnd.vaadin.gwtStatsEvents || [];
- }-*/;
-
- /**
- * Add logger if it's not already there, also initializing the event array
- * if needed.
- */
- private static native void ensureLogger()
- /*-{
- if (typeof $wnd.__gwtStatsEvent != 'function') {
- if (typeof $wnd.vaadin.gwtStatsEvents != 'object') {
- $wnd.vaadin.gwtStatsEvents = [];
- }
- $wnd.__gwtStatsEvent = function(event) {
- $wnd.vaadin.gwtStatsEvents.push(event);
- return true;
- }
- }
- }-*/;
-
- /**
- * Remove logger function and event array if it seems like the function has
- * been added by us.
- */
- private static native void ensureNoLogger()
- /*-{
- if (typeof $wnd.vaadin.gwtStatsEvents == 'object') {
- delete $wnd.vaadin.gwtStatsEvents;
- if (typeof $wnd.__gwtStatsEvent == 'function') {
- $wnd.__gwtStatsEvent = function() { return true; };
- }
- }
- }-*/;
-
- private static native JsArray<GwtStatsEvent> clearEventsList()
- /*-{
- $wnd.vaadin.gwtStatsEvents = [];
- }-*/;
-
- /**
- * Sets the profiler result consumer that is used to output the profiler
- * data to the user.
- * <p>
- * <b>Warning!</b> This is internal API and should not be used by
- * applications or add-ons.
- *
- * @since 7.1.4
- * @param profilerResultConsumer
- * the consumer that gets profiler data
- */
- public static void setProfilerResultConsumer(
- ProfilerResultConsumer profilerResultConsumer) {
- if (consumer != null) {
- throw new IllegalStateException(
- "The consumer has already been set");
- }
- consumer = profilerResultConsumer;
- }
-
- private static ProfilerResultConsumer getConsumer() {
- return consumer;
- }
-
- private static Logger getLogger() {
- return Logger.getLogger(Profiler.class.getName());
- }
-
- private static native boolean hasHighPrecisionTime()
- /*-{
- return $wnd.performance && (typeof $wnd.performance.now == 'function');
- }-*/;
-
- private interface RelativeTimeSupplier {
- double getRelativeTime();
- }
-
- private static class DefaultRelativeTimeSupplier
- implements RelativeTimeSupplier {
-
- @Override
- public native double getRelativeTime()
- /*-{
- return (new Date).getTime();
- }-*/;
- }
-
- private static class HighResolutionTimeSupplier
- implements RelativeTimeSupplier {
-
- @Override
- public native double getRelativeTime()
- /*-{
- return $wnd.performance.now();
- }-*/;
- }
- }
|