You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@sling.apache.org by ra...@apache.org on 2022/03/04 14:08:02 UTC

[sling-org-apache-sling-scripting-core] branch issue/SLING-11182 created (now 48a9080)

This is an automated email from the ASF dual-hosted git repository.

radu pushed a change to branch issue/SLING-11182
in repository https://gitbox.apache.org/repos/asf/sling-org-apache-sling-scripting-core.git.


      at 48a9080  SLING-11182 - Correct potential errors introduced by BVP logging

This branch includes the following new commits:

     new 48a9080  SLING-11182 - Correct potential errors introduced by BVP logging

The 1 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails.  The revisions
listed as "add" were already present in the repository and have only
been added to this reference.


[sling-org-apache-sling-scripting-core] 01/01: SLING-11182 - Correct potential errors introduced by BVP logging

Posted by ra...@apache.org.
This is an automated email from the ASF dual-hosted git repository.

radu pushed a commit to branch issue/SLING-11182
in repository https://gitbox.apache.org/repos/asf/sling-org-apache-sling-scripting-core.git

commit 48a9080216c78412967ec4d67a5bd6b1c10398b9
Author: Radu Cotescu <ra...@apache.org>
AuthorDate: Fri Mar 4 14:53:06 2022 +0100

    SLING-11182 - Correct potential errors introduced by BVP logging
    
    * log conditionally: request progress tracker or normal component log
---
 .../scripting/core/impl/DefaultSlingScript.java    | 21 ++++++++++++++-----
 .../core/impl/bundled/ScriptContextProvider.java   | 24 ++++++++++++++++------
 2 files changed, 34 insertions(+), 11 deletions(-)

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 c127cde..fa7df41 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
@@ -92,6 +92,10 @@ class DefaultSlingScript implements SlingScript, Servlet, ServletConfig {
     /** is defined on multiple files in this bundle*/
     private static final long WARN_LIMIT_FOR_BVP_NANOS = (1000*1000); // 1 ms
 
+    private static final String BINDINGS_THRESHOLD_MESSAGE = "Adding the bindings of %s took %s microseconds which is above the hardcoded" +
+            " limit of %s microseconds; if this message appears often it indicates that this BindingsValuesProvider has an impact on " +
+            "general page rendering performance.";
+
     /** Thread local containing the resource resolver. */
     private static ThreadLocal<ResourceResolver> requestResourceResolver = new ThreadLocal<ResourceResolver>();
 
@@ -742,13 +746,20 @@ class DefaultSlingScript implements SlingScript, Servlet, ServletConfig {
                 LOGGER.trace("Invoking addBindings() of {} took {} nanoseconds",
                         provider.getClass().getName(), stop-start);
                 if (stop-start > WARN_LIMIT_FOR_BVP_NANOS) {
-                    LOGGER.info("Adding the bindings of {} took {} microseconds which is above the harcoded limit of {} microseconds;"
-                            + " if this message appears often it indicates that this BindingsValuesProvider has an impact on general page rendering performance",
-                            new Object[]{provider.getClass().getName(), (stop-start)/1000, WARN_LIMIT_FOR_BVP_NANOS/1000});
+                    // SLING-11182 - make this work with older implementations of the Sling API
+                    if (request != null && request.getRequestProgressTracker() != null) {
+                        request.getRequestProgressTracker().log(String.format(BINDINGS_THRESHOLD_MESSAGE, provider.getClass().getName(), (stop-start)/1000, WARN_LIMIT_FOR_BVP_NANOS/1000));
+                    } else {
+                        LOGGER.info(String.format(BINDINGS_THRESHOLD_MESSAGE, provider.getClass().getName(), (stop-start)/1000,
+                                WARN_LIMIT_FOR_BVP_NANOS/1000));
+                    }
                 }
             }
-            long duration = (System.nanoTime() - inclusionStart) / 1000;
-            request.getRequestProgressTracker().log("Adding bindings took " + duration + " microseconds");
+            // SLING-11182 - make this work with older implementations of the Sling API
+            if (request != null && request.getRequestProgressTracker() != null) {
+                long duration = (System.nanoTime() - inclusionStart) / 1000;
+                request.getRequestProgressTracker().log("Adding bindings took " + duration + " microseconds");
+            }
         }
 
         return bindings;
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 bdc0a16..02056f7 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
@@ -59,6 +59,10 @@ public class ScriptContextProvider {
     /** is defined on multiple files in this bundle*/
     private static final long WARN_LIMIT_FOR_BVP_NANOS = (1000*1000); // 1 ms
 
+    private static final String BINDINGS_THRESHOLD_MESSAGE = "Adding the bindings of %s took %s microseconds which is above the hardcoded" +
+            " limit of %s microseconds; if this message appears often it indicates that this BindingsValuesProvider has an impact on " +
+            "general page rendering performance.";
+
     private static final Set<String> PROTECTED_BINDINGS = Collections.unmodifiableSet(new HashSet<>(Arrays.asList(
             SlingBindings.REQUEST,
             SlingBindings.RESPONSE,
@@ -121,14 +125,22 @@ public class ScriptContextProvider {
             long stop = System.nanoTime();
             LOG.trace("Invoking addBindings() of {} took {} nanoseconds",
                     bindingsValuesProvider.getClass().getName(), stop-start);
-            if ((stop-start) > WARN_LIMIT_FOR_BVP_NANOS) {
-                LOG.info("Adding the bindings of {} took {} microseconds which is above the hardcoded limit of {} microseconds;"
-                        + " if this message appears often it indicates that this BindingsValuesProvider has an impact on general page rendering performance",
-                        new Object[]{bindingsValuesProvider.getClass().getName(), (stop-start)/1000, WARN_LIMIT_FOR_BVP_NANOS/1000});
+            if (stop-start > WARN_LIMIT_FOR_BVP_NANOS) {
+                // SLING-11182 - make this work with older implementations of the Sling API
+                if (request.getRequestProgressTracker() != null) {
+                    request.getRequestProgressTracker().log(String.format(BINDINGS_THRESHOLD_MESSAGE, bindingsValuesProvider.getClass().getName(),
+                            (stop-start)/1000, WARN_LIMIT_FOR_BVP_NANOS/1000));
+                } else {
+                    LOG.info(String.format(BINDINGS_THRESHOLD_MESSAGE, bindingsValuesProvider.getClass().getName(), (stop-start)/1000,
+                            WARN_LIMIT_FOR_BVP_NANOS/1000));
+                }
             }
         }
-        long duration = (System.nanoTime() - inclusionStart) / 1000;
-        request.getRequestProgressTracker().log("Adding bindings took " + duration + " microseconds");
+        // SLING-11182 - make this work with older implementations of the Sling API
+        if (request.getRequestProgressTracker() != null) {
+            long duration = (System.nanoTime() - inclusionStart) / 1000;
+            request.getRequestProgressTracker().log("Adding bindings took " + duration + " microseconds");
+        }
 
         ScriptContext scriptContext = new BundledScriptContext();
         Map<String, LazyBindings.Supplier> slingBindingsSuppliers = new HashMap<>();