This is an automated email from the ASF dual-hosted git repository. joerghoh pushed a commit to branch improvement/SLING-10584-BVP-timing in repository https://gitbox.apache.org/repos/asf/sling-org-apache-sling-scripting-core.git
commit 7ab30eddd0d89686e6bb1bf4f46e031b46aa9ced Author: Joerg Hoh <[email protected]> AuthorDate: Tue Jul 6 21:19:41 2021 +0200 SLING-10584 log an info message if adding bindings takes more than 1 msec --- .../org/apache/sling/scripting/core/impl/DefaultSlingScript.java | 6 ++++++ .../sling/scripting/core/impl/bundled/ScriptContextProvider.java | 8 ++++++++ 2 files changed, 14 insertions(+) diff --git a/src/main/java/org/apache/sling/scripting/core/impl/DefaultSlingScript.java b/src/main/java/org/apache/sling/scripting/core/impl/DefaultSlingScript.java index 519080d..670350a 100644 --- a/src/main/java/org/apache/sling/scripting/core/impl/DefaultSlingScript.java +++ b/src/main/java/org/apache/sling/scripting/core/impl/DefaultSlingScript.java @@ -732,7 +732,13 @@ class DefaultSlingScript implements SlingScript, Servlet, ServletConfig { ProtectedBindings protectedBindings = new ProtectedBindings(bindings, protectedKeys); for (BindingsValuesProvider provider : bindingsValuesProviders) { + long start = System.nanoTime(); provider.addBindings(protectedBindings); + long stop = System.nanoTime(); + if (start-stop > (1000*1000)) { // 1 ms + LOGGER.info("Adding the bindings of {} took {} microseconds, it might impact general performance", + provider.getClass().getName(), (start-stop)/1000); + } } } diff --git a/src/main/java/org/apache/sling/scripting/core/impl/bundled/ScriptContextProvider.java b/src/main/java/org/apache/sling/scripting/core/impl/bundled/ScriptContextProvider.java index 3ce7ef1..76f3423 100644 --- a/src/main/java/org/apache/sling/scripting/core/impl/bundled/ScriptContextProvider.java +++ b/src/main/java/org/apache/sling/scripting/core/impl/bundled/ScriptContextProvider.java @@ -52,6 +52,8 @@ import org.slf4j.LoggerFactory; service = ScriptContextProvider.class ) public class ScriptContextProvider { + + private static final Logger LOG = LoggerFactory.getLogger(ScriptContextProvider.class); private static final Set<String> PROTECTED_BINDINGS = Collections.unmodifiableSet(new HashSet<>(Arrays.asList( SlingBindings.REQUEST, @@ -105,7 +107,13 @@ public class ScriptContextProvider { ProtectedBindings protectedBindings = new ProtectedBindings(bindings, PROTECTED_BINDINGS); for (BindingsValuesProvider bindingsValuesProvider : bvpTracker.getBindingsValuesProviders(scriptEngine.getFactory(), BindingsValuesProvider.DEFAULT_CONTEXT)) { + long start = System.nanoTime(); bindingsValuesProvider.addBindings(protectedBindings); + long stop = System.nanoTime(); + if ((stop-start) > (1000*1000)) { // 1ms + LOG.info("Adding the bindings of {} took {} microseconds, it might impact general performance", + bindingsValuesProvider.getClass().getName(), (start-stop)/1000); + } } ScriptContext scriptContext = new BundledScriptContext(); Map<String, LazyBindings.Supplier> slingBindingsSuppliers = new HashMap<>();
