Add timings back with a native event

src/main/java/ch/njol/skript/SkriptEventHandler.java

@@ -2,6 +2,8 @@
 
 import ch.njol.skript.lang.SkriptEvent;
 import ch.njol.skript.lang.Trigger;
+import ch.njol.skript.timings.Profiler;
+import ch.njol.skript.timings.ProfilerAPI;
 import ch.njol.skript.timings.SkriptTimings;
 import ch.njol.skript.util.Task;
 import com.google.common.collect.ArrayListMultimap;
@@ -162,8 +164,17 @@ private static void execute(Trigger trigger, Event event) {
 		Runnable execute = () -> {
 			logTriggerStart(trigger);
 			Object timing = SkriptTimings.start(trigger.getDebugLabel());
+
+			boolean skipProfiling = ProfilerAPI.isFiringProfilerEvent.get();
+			Profiler profiler = skipProfiling ? null : ProfilerAPI.start(trigger.getDebugLabel());
+
 			trigger.execute(event);
 			SkriptTimings.stop(timing);
+
+			if (!skipProfiling) {
+				ProfilerAPI.stop(profiler);
+			}
+
 			logTriggerEnd(trigger);
 		};
 

src/main/java/ch/njol/skript/command/ScriptCommand.java

@@ -205,7 +205,9 @@ public ScriptCommand(
 		this.arguments = arguments;
 
 		trigger = new Trigger(script, "command /" + name, new SimpleEvent(), ScriptLoader.loadItems(node));
-		trigger.setLineNumber(node.getLine());
+		int lineNumber = node.getLine();
+		trigger.setLineNumber(lineNumber);
+		trigger.setDebugLabel(script.nameAndPath() + ".sk: line " + lineNumber + " part of command /" + name);
 
 		bukkitCommand = setupBukkitCommand();
 	}

src/main/java/ch/njol/skript/effects/Delay.java

@@ -11,6 +11,8 @@
 import ch.njol.skript.lang.SkriptParser.ParseResult;
 import ch.njol.skript.lang.Trigger;
 import ch.njol.skript.lang.TriggerItem;
+import ch.njol.skript.timings.Profiler;
+import ch.njol.skript.timings.ProfilerAPI;
 import ch.njol.skript.timings.SkriptTimings;
 import ch.njol.skript.util.Timespan;
 import ch.njol.skript.variables.Variables;
@@ -80,6 +82,14 @@ protected TriggerItem walk(Event event) {
 					Variables.setLocalVariables(event, localVars);
 
 				Object timing = null; // Timings reference must be kept so that it can be stopped after TriggerItem execution
+				Profiler profiler = null;
+
+				if (ProfilerAPI.enabled()) {
+					Trigger trigger = getTrigger();
+					if (trigger != null)
+						profiler = ProfilerAPI.start(trigger.getDebugLabel());
+				}
+
 				if (SkriptTimings.enabled()) { // getTrigger call is not free, do it only if we must
 					Trigger trigger = getTrigger();
 					if (trigger != null)
@@ -90,6 +100,7 @@ protected TriggerItem walk(Event event) {
 				Variables.removeLocals(event); // Clean up local vars, we may be exiting now
 
 				SkriptTimings.stop(timing); // Stop timing if it was even started
+				ProfilerAPI.stop(profiler);
 			}, Math.max(duration.getAs(Timespan.TimePeriod.TICK), 1)); // Minimum delay is one tick, less than it is useless!
 		}
 		return null;

src/main/java/ch/njol/skript/effects/EffTeleport.java

@@ -6,6 +6,8 @@
 import ch.njol.skript.lang.*;
 import ch.njol.skript.lang.SkriptParser.ParseResult;
 import ch.njol.skript.sections.EffSecSpawn.SpawnEvent;
+import ch.njol.skript.timings.Profiler;
+import ch.njol.skript.timings.ProfilerAPI;
 import ch.njol.skript.timings.SkriptTimings;
 import ch.njol.skript.util.Direction;
 import ch.njol.skript.variables.Variables;
@@ -150,6 +152,7 @@ public boolean init(Expression<?>[] exprs, int matchedPattern, Kleenean isDelaye
 
 			// Continue the rest of the trigger if there is one
 			Object timing = null;
+			Profiler profiler = null;
 			if (next != null) {
 				if (SkriptTimings.enabled()) {
 					Trigger trigger = getTrigger();
@@ -158,10 +161,18 @@ public boolean init(Expression<?>[] exprs, int matchedPattern, Kleenean isDelaye
 					}
 				}
 
+				if (ProfilerAPI.enabled()) {
+					Trigger trigger = getTrigger();
+					if (trigger != null) {
+						profiler = ProfilerAPI.start(trigger.getDebugLabel());
+					}
+				}
+
 				TriggerItem.walk(next, event);
 			}
 			Variables.removeLocals(event); // Clean up local vars, we may be exiting now
 			SkriptTimings.stop(timing);
+			ProfilerAPI.stop(profiler);
 		});
 		return null;
 	}

src/main/java/ch/njol/skript/events/EvtProfileEvent.java

@@ -0,0 +1,53 @@
+package ch.njol.skript.events;
+
+import ch.njol.skript.Skript;
+import ch.njol.skript.events.bukkit.ProfileCompletedEvent;
+import ch.njol.skript.lang.Literal;
+import ch.njol.skript.lang.SkriptEvent;
+import ch.njol.skript.lang.SkriptParser.ParseResult;
+import org.bukkit.event.Event;
+import org.jetbrains.annotations.Nullable;
+import ch.njol.skript.registrations.EventValues;
+import ch.njol.skript.util.Getter;
+
+public class EvtProfileEvent extends SkriptEvent {
+	static {
+		Skript.registerEvent("Profiler Event Available", EvtProfileEvent.class, ProfileCompletedEvent.class,
+				"(profile|profiler) [event] (complete|completed|available)")
+			.description("Called after a new profiler event is available")
+			.since("INSERT VERSION");
+
+		EventValues.registerEventValue(
+			ProfileCompletedEvent.class,
+			String.class,
+			ProfileCompletedEvent::getName
+		);
+
+		EventValues.registerEventValue(
+			ProfileCompletedEvent.class,
+			Number.class,
+			ProfileCompletedEvent::getDurationMs
+		);
+	}
+
+	@Override
+	public boolean init(Literal<?>[] args, int matchedPattern, ParseResult parser) {
+		return true;
+	}
+
+	@Override
+	public boolean check(Event event) {
+		return event instanceof ProfileCompletedEvent;
+	}
+
+	@Override
+	public boolean isEventPrioritySupported() {
+		return false;
+	}
+
+	@Override
+	public String toString(@Nullable Event event, boolean debug) {
+		return "profile event complete";
+	}
+
+}

src/main/java/ch/njol/skript/events/bukkit/ProfileCompletedEvent.java

@@ -0,0 +1,59 @@
+package ch.njol.skript.events.bukkit;
+
+import org.bukkit.event.Event;
+import org.bukkit.event.HandlerList;
+import org.jetbrains.annotations.NotNull;
+
+/**
+ * Represents a custom event triggered when a profiling section is completed.
+ * This event holds information about the name of the profiling section and
+ * the time it took to complete in milliseconds.
+ */
+public class ProfileCompletedEvent extends Event {
+	private static final HandlerList handlers = new HandlerList();
+	private final String sectionName;
+	private final double durationMs;
+
+	/**
+	 * Constructs a new ProfileCompletedEvent.
+	 * @param sectionName the name of the profiling section
+	 * @param durationMs  the duration in milliseconds the section took to execute
+	 */
+	public ProfileCompletedEvent(String sectionName, double durationMs) {
+		this.sectionName = sectionName;
+		this.durationMs = durationMs;
+	}
+
+	/**
+	 * Gets the name of the profiling section that was completed.
+	 * @return the name of the completed profiling section
+	 */
+	public String getName() {
+		return sectionName;
+	}
+
+	/**
+	 * Gets the duration in milliseconds that the profiling section took to complete.
+	 * @return the execution time of the section in milliseconds
+	 */
+	public double getDurationMs() {
+		return durationMs;
+	}
+
+	/**
+	 * Gets the list of handlers registered for this event.
+	 * @return the list of handlers
+	 */
+	@Override
+	public @NotNull HandlerList getHandlers() {
+		return handlers;
+	}
+
+	/**
+	 * Gets the static handler list for this event class.
+	 * @return the static handler list
+	 */
+	public static HandlerList getHandlerList() {
+		return handlers;
+	}
+}

src/main/java/ch/njol/skript/lang/Section.java

@@ -10,6 +10,7 @@
 import org.jetbrains.annotations.ApiStatus;
 import org.jetbrains.annotations.NotNull;
 import org.jetbrains.annotations.Nullable;
+import org.skriptlang.skript.lang.script.Script;
 
 import java.util.ArrayList;
 import java.util.Iterator;
@@ -137,7 +138,11 @@ protected final Trigger loadCode(SectionNode sectionNode, String name, @Nullable
 		// return the parser to its original state
 		parser.restoreBackup(parserBackup);
 
-		return new Trigger(parser.getCurrentScript(), name, skriptEvent, triggerItems);
+		Script script = parser.getCurrentScript();
+		Trigger trigger = new Trigger(script, name, skriptEvent, triggerItems);
+		trigger.setDebugLabel(script.nameAndPath() + ".sk: line " + sectionNode.getLine() + " as part of section " + name);
+
+		return trigger;
 	}
 
 	/**

src/main/java/ch/njol/skript/lang/SkriptEvent.java

@@ -132,7 +132,7 @@ public boolean load() {
 			trigger = new Trigger(script, expr, this, items);
 			int lineNumber = source.getLine();
 			trigger.setLineNumber(lineNumber); // Set line number for debugging
-			trigger.setDebugLabel(script + ": line " + lineNumber);
+			trigger.setDebugLabel(script.nameAndPath() + ".sk: line " + lineNumber + " (expr " + expr + ")");
 		} finally {
 			getParser().deleteCurrentEvent();
 		}

src/main/java/ch/njol/skript/timings/Profiler.java

@@ -0,0 +1,48 @@
+package ch.njol.skript.timings;
+
+import ch.njol.skript.Skript;
+
+/**
+ * Profiler instance for the ProfilerAPI
+ * Each profiler times how long it takes for a given trigger to complete,
+ * along with the invocator script information
+ */
+public class Profiler {
+	private final String name;
+	private long startTime = 0;
+	private long totalTime = 0;
+	private boolean running = false;
+
+	public Profiler(String name) {
+		this.name = name;
+	}
+
+	public void start() {
+		if (running) return; // prevent double-starts
+		startTime = System.nanoTime();
+		running = true;
+	}
+
+	public void stop() {
+		if (!running) return; // prevent stop without start
+		long endTime = System.nanoTime();
+		long duration = endTime - startTime;
+		totalTime += duration;
+		running = false;
+
+		Skript.debug("[Profiler] " + name + " took " + (duration / 1_000_000.0) + " ms");
+	}
+
+	public long getTimeNanos() {
+		return totalTime;
+	}
+
+	public double getTime() {
+		return totalTime / 1_000_000.0;
+	}
+
+	public String getName() {
+		return name;
+	}
+
+}

src/main/java/ch/njol/skript/timings/ProfilerAPI.java

@@ -0,0 +1,48 @@
+package ch.njol.skript.timings;
+
+import ch.njol.skript.Skript;
+import ch.njol.skript.events.bukkit.ProfileCompletedEvent;
+import ch.njol.skript.timings.Profiler;
+import org.bukkit.Bukkit;
+import org.jetbrains.annotations.Nullable;
+
+/**
+ * Profiler API for timing how long a given event takes
+ */
+public class ProfilerAPI {
+
+	private static volatile boolean enabled = true;
+	public static final ThreadLocal<Boolean> isFiringProfilerEvent = ThreadLocal.withInitial(() -> false);
+
+	@Nullable
+	public static Profiler start(String name) {
+		if (!enabled()) // Timings disabled :(
+			return null;
+		Profiler profiler = new Profiler(name);
+		profiler.start();
+		return profiler;
+	}
+
+	public static void stop(@Nullable Profiler profiler) {
+		if (profiler == null) // Timings disabled...
+			return;
+		profiler.stop();
+
+		if (isFiringProfilerEvent.get()) return;
+		isFiringProfilerEvent.set(true);
+		try {
+			Bukkit.getPluginManager().callEvent(new ProfileCompletedEvent(profiler.getName(), profiler.getTime()));
+		} finally {
+			isFiringProfilerEvent.set(false);
+		}
+	}
+
+	public static boolean enabled() {
+		return enabled;
+	}
+
+	public static void setEnabled(boolean flag) {
+		enabled = flag;
+	}
+
+}

src/main/java/ch/njol/skript/util/AsyncEffect.java

@@ -1,5 +1,7 @@
 package ch.njol.skript.util;
 
+import ch.njol.skript.timings.Profiler;
+import ch.njol.skript.timings.ProfilerAPI;
 import org.bukkit.Bukkit;
 import org.bukkit.event.Event;
 import org.jetbrains.annotations.Nullable;
@@ -44,18 +46,27 @@ protected TriggerItem walk(Event e) {
 			if (getNext() != null) {
 				Bukkit.getScheduler().runTask(Skript.getInstance(), () -> { // Walk to next item synchronously
 					Object timing = null;
+					Profiler profiler = null;
 					if (SkriptTimings.enabled()) { // getTrigger call is not free, do it only if we must
 						Trigger trigger = getTrigger();
 						if (trigger != null) {
 							timing = SkriptTimings.start(trigger.getDebugLabel());
 						}
 					}
+
+					if (ProfilerAPI.enabled()) {
+						Trigger trigger = getTrigger();
+						if (trigger != null) {
+							profiler = ProfilerAPI.start(trigger.getDebugLabel());
+						}
+					}
 
 					TriggerItem.walk(getNext(), e);
 
 					Variables.removeLocals(e); // Clean up local vars, we may be exiting now
 
 					SkriptTimings.stop(timing); // Stop timing if it was even started
+					ProfilerAPI.stop(profiler);
 				});
 			} else {
 				Variables.removeLocals(e);