You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@sling.apache.org by cz...@apache.org on 2022/03/15 10:57:11 UTC

[sling-org-apache-sling-api] branch master updated: SLING-11206 : Add support for buidling RequestProgressTracker

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

cziegeler pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/sling-org-apache-sling-api.git


The following commit(s) were added to refs/heads/master by this push:
     new 159d446  SLING-11206 : Add support for buidling RequestProgressTracker
159d446 is described below

commit 159d446c65725ebaba2bdc4a5d9d8feb50ea64ac
Author: Carsten Ziegeler <cz...@apache.org>
AuthorDate: Tue Mar 15 11:56:04 2022 +0100

    SLING-11206 : Add support for buidling RequestProgressTracker
---
 pom.xml                                            |   3 +-
 .../apache/sling/api/request/builder/Builders.java |  12 +
 .../builder/SlingHttpServletRequestBuilder.java    |   9 +
 .../request/builder/impl/FastMessageFormat.java    | 105 +++++++
 .../builder/impl/RequestProgressTrackerImpl.java   | 308 +++++++++++++++++++--
 .../builder/impl/SlingHttpServletRequestImpl.java  |  18 +-
 .../sling/api/request/builder/package-info.java    |   2 +-
 .../sling/api/request/builder/BuildersTest.java    |   7 +
 .../builder/impl/FastMessageFormatTest.java        |  81 ++++++
 .../impl/RequestProgressTrackerImplTest.java       | 140 ++++++++--
 .../impl/SlingHttpServletRequestImplTest.java      |  20 +-
 11 files changed, 654 insertions(+), 51 deletions(-)

diff --git a/pom.xml b/pom.xml
index 3bf993b..c8b773b 100644
--- a/pom.xml
+++ b/pom.xml
@@ -28,7 +28,7 @@
     </parent>
 
     <artifactId>org.apache.sling.api</artifactId>
-    <version>2.24.1-SNAPSHOT</version>
+    <version>2.25.0-SNAPSHOT</version>
 
     <name>Apache Sling API</name>
     <description>
@@ -46,7 +46,6 @@
         <connection>scm:git:https://gitbox.apache.org/repos/asf/sling-org-apache-sling-api.git</connection>
         <developerConnection>scm:git:https://gitbox.apache.org/repos/asf/sling-org-apache-sling-api.git</developerConnection>
         <url>https://gitbox.apache.org/repos/asf?p=sling-org-apache-sling-api.git</url>
-      <tag>org.apache.sling.api-2.24.0</tag>
   </scm>
 
     <properties>
diff --git a/src/main/java/org/apache/sling/api/request/builder/Builders.java b/src/main/java/org/apache/sling/api/request/builder/Builders.java
index 20f952c..8089f0e 100644
--- a/src/main/java/org/apache/sling/api/request/builder/Builders.java
+++ b/src/main/java/org/apache/sling/api/request/builder/Builders.java
@@ -18,6 +18,8 @@
  */
 package org.apache.sling.api.request.builder;
 
+import org.apache.sling.api.request.RequestProgressTracker;
+import org.apache.sling.api.request.builder.impl.RequestProgressTrackerImpl;
 import org.apache.sling.api.request.builder.impl.SlingHttpServletRequestImpl;
 import org.apache.sling.api.request.builder.impl.SlingHttpServletResponseImpl;
 import org.apache.sling.api.resource.Resource;
@@ -51,4 +53,14 @@ public final class Builders {
     public static @NotNull SlingHttpServletResponseBuilder newResponseBuilder() {
         return new SlingHttpServletResponseImpl();
     }
+
+    /**
+     * Creates a new request progress tracker
+     *
+     * @return a request progress tracker
+     * @since 1.1 (Sling API Bundle 2.25.0)
+     */
+    public static @NotNull RequestProgressTracker newRequestProgressTracker() {
+        return new RequestProgressTrackerImpl();
+    }
 }
diff --git a/src/main/java/org/apache/sling/api/request/builder/SlingHttpServletRequestBuilder.java b/src/main/java/org/apache/sling/api/request/builder/SlingHttpServletRequestBuilder.java
index 8b21cf2..0c3675a 100644
--- a/src/main/java/org/apache/sling/api/request/builder/SlingHttpServletRequestBuilder.java
+++ b/src/main/java/org/apache/sling/api/request/builder/SlingHttpServletRequestBuilder.java
@@ -23,6 +23,7 @@ import java.util.Map;
 import javax.servlet.http.HttpServletRequest;
 
 import org.apache.sling.api.SlingHttpServletRequest;
+import org.apache.sling.api.request.RequestProgressTracker;
 import org.jetbrains.annotations.NotNull;
 import org.jetbrains.annotations.Nullable;
 import org.osgi.annotation.versioning.ProviderType;
@@ -136,6 +137,14 @@ public interface SlingHttpServletRequestBuilder {
     @NotNull SlingHttpServletRequestBuilder useServletContextFrom(@NotNull HttpServletRequest request);
 
     /**
+     * Uses the provided request progress tracker
+     * @param tracker The tracker
+     * @return this object
+     * @since 1.1 (Sling API Bundle 2.25.0)
+     */
+    @NotNull SlingHttpServletRequestBuilder withRequestProgressTracker(@NotNull RequestProgressTracker tracker);
+
+    /**
      * Builds the request. Once this method has been called, the builder must not be used anymore. In order to create a new request a new
      * builder has to be used.
      * @return a request object
diff --git a/src/main/java/org/apache/sling/api/request/builder/impl/FastMessageFormat.java b/src/main/java/org/apache/sling/api/request/builder/impl/FastMessageFormat.java
new file mode 100644
index 0000000..86eed73
--- /dev/null
+++ b/src/main/java/org/apache/sling/api/request/builder/impl/FastMessageFormat.java
@@ -0,0 +1,105 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements.  See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership.  The ASF licenses this file
+ * to you 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 org.apache.sling.api.request.builder.impl;
+
+import java.text.DateFormat;
+import java.text.MessageFormat;
+import java.text.NumberFormat;
+import java.util.Date;
+
+/**
+ * Fast MessageFormat implementation which is not thread-safe. It is based on the assumptions that
+ * <ul>
+ *     <li>most formats do not contain format types and styles</li>
+ *     <li>do not use escaping</li>
+ *     <li>format elements are in order</li>
+ * </ul>
+ *
+ * If one of these assumptions fails, then it falls back to the original {@link MessageFormat}.<br>
+ * To increase the benefit of this implementation, every instance should be reused as often as possible.
+ */
+public class FastMessageFormat {
+
+    // Reusable formats instances. Cannot be static because these classes are not thread safe.
+    private NumberFormat numberFormat;
+    private DateFormat dateFormat;
+
+    private NumberFormat getNumberFormat() {
+        if (numberFormat == null) {
+            numberFormat = NumberFormat.getNumberInstance();
+        }
+        return numberFormat;
+    }
+
+    private DateFormat getDateFormat() {
+        if (dateFormat == null) {
+            dateFormat = DateFormat.getDateTimeInstance(DateFormat.SHORT, DateFormat.SHORT);
+        }
+        return dateFormat;
+    }
+
+    /**
+     * Use this method exactly like {@link MessageFormat#format(String, Object...)}.
+     *
+     * @param pattern the pattern to use
+     * @param arguments the objects to format
+     * @return the string which has been formatted.
+     *
+     * @see MessageFormat#format(String, Object...)
+     */
+    public String format(String pattern, Object... arguments) {
+        if (arguments == null || arguments.length == 0) {
+            return pattern;
+        } else {
+            if (pattern.indexOf('\'') != -1) {
+                // Escaping is not supported, fall back
+                return MessageFormat.format(pattern, arguments);
+            } else {
+                StringBuilder message = new StringBuilder();
+                int previousEnd = 0;
+                for (int i = 0; i < arguments.length; i++) {
+                    String placeholder = '{' + String.valueOf(i);
+                    int placeholderIndex = pattern.indexOf(placeholder);
+                    // -1 or before previous placeholder || format element with type/style
+                    if (placeholderIndex < previousEnd
+                            || pattern.charAt(placeholderIndex + placeholder.length()) != '}') {
+                        // Type, style and random order are not supported, fall back
+                        return MessageFormat.format(pattern, arguments);
+                    } else {
+                        // Format argument if necessary
+                        Object argument = arguments[i];
+                        if (argument instanceof Number) {
+                            argument = getNumberFormat().format(argument);
+                        } else if (argument instanceof Date) {
+                            argument = getDateFormat().format(argument);
+                        }
+
+                        // Append previous part of the string and formatted argument
+                        message.append(pattern.substring(previousEnd, placeholderIndex));
+                        message.append(argument);
+                        previousEnd = placeholderIndex + placeholder.length() + 1;
+                    }
+                }
+                message.append(pattern.substring(previousEnd, pattern.length()));
+                return message.toString();
+            }
+        }
+    }
+
+}
diff --git a/src/main/java/org/apache/sling/api/request/builder/impl/RequestProgressTrackerImpl.java b/src/main/java/org/apache/sling/api/request/builder/impl/RequestProgressTrackerImpl.java
index a0d7836..2cc1b09 100644
--- a/src/main/java/org/apache/sling/api/request/builder/impl/RequestProgressTrackerImpl.java
+++ b/src/main/java/org/apache/sling/api/request/builder/impl/RequestProgressTrackerImpl.java
@@ -19,53 +19,315 @@
 package org.apache.sling.api.request.builder.impl;
 
 import java.io.PrintWriter;
-import java.util.Collections;
+import java.util.ArrayList;
+import java.util.HashMap;
 import java.util.Iterator;
+import java.util.List;
+import java.util.Map;
+
+import javax.servlet.http.HttpServletRequest;
 
 import org.apache.sling.api.request.RequestProgressTracker;
 
 /**
- * Internal {@link RequestProgressTracker} implementation.
+ * The <code>SlingRequestProgressTracker</code> class provides the
+ * functionality to track the progress of request processing. Instances of this
+ * class are provided through the
+ * {@link org.apache.sling.api.SlingHttpServletRequest#getRequestProgressTracker()}
+ * method.
+ * <p>
+ * The following functionality is provided:
+ * <ol>
+ * <li>Track the progress of request processing through the
+ * {@link #log(String)} and {@link #log(String, Object...)} methods.
+ * <li>Ability to measure and track processing times of parts of request
+ * processing through the {@link #startTimer(String)} and
+ * {@link #logTimer(String)} methods.
+ * <li>Dumping the recording messages through the
+ * {@link #dump(PrintWriter)} method.
+ * <li>Resetting the tracker through the {@link #reset()} method.
+ * </ol>
+ * <p>
+ * <b>Tracking Request Processing</b>
+ * <p>
+ * As the request being processed, certain steps may be tracked by calling
+ * either of the <code>log</code> methods. A tracking entry consists of a time
+ * stamp managed by this class, and a tracking message noting the actual step being
+ * tracked.
+ * <p>
+ * <b>Timing Processing Steps</b>
+ * </p>
+ * Certain steps during request processing may need to be timed in that the time
+ * required for processing should be recorded. Instances of this class maintain
+ * a map of named timers. Each timer is started (initialized or reset) by
+ * calling the {@link #startTimer(String)} method. This method just records the
+ * starting time of the named timer.
+ * <p>
+ * To record the number of milliseconds ellapsed since a timer has been started,
+ * the {@link #logTimer(String)} method may be called. This method logs the
+ * tracking entry with message
+ * consisting of the name of the timer and the number of milliseconds ellapsed
+ * since the timer was last {@link #startTimer(String) started}. The
+ * {@link #logTimer(String)} method may be called multiple times to record
+ * several timed steps.
+ * <p>
+ * Additional information can be logged using the {@link #logTimer(String, String, Object...)}
+ * method.
+ * <p>
+ * Calling the {@link #startTimer(String)} method with the name of timer which
+ * already exists, resets the start time of the named timer to the current
+ * system time.
+ * <p>
+ * <b>Dumping Tracking Entries</b>
+ * <p>
+ * The {@link #dump(PrintWriter)} methods writes all tracking entries to the given
+ * <code>PrintWriter</code>. Each entry is written on a single line
+ * consisting of the following fields:
+ * <ol>
+ * <li>The number of milliseconds since the last {@link #reset()} (or creation)
+ * of this timer.
+ * <li>The absolute time of the timer in parenthesis.
+ * <li>The entry message
+ * </ol>
  */
 public class RequestProgressTrackerImpl implements RequestProgressTracker {
 
-    @Override
+    /**
+     * The name of the timer tracking the processing time of the complete
+     * process.
+     */
+    private static final String REQUEST_PROCESSING_TIMER = "Request Processing";
+
+    /** Prefix for log messages */
+    private static final String LOG_PREFIX = "LOG ";
+
+    /** Prefix for comment messages */
+    private static final String COMMENT_PREFIX = "COMMENT ";
+
+    /** TIMER_END format explanation */
+    private static final String TIMER_END_FORMAT = "{<elapsed microseconds>,<timer name>} <optional message>";
+
+    /** The leading nanosecond number is left-padded with white-space to this width. */
+    private static final int PADDING_WIDTH = 7;
+
+    /**
+     * The system time at creation of this instance or the last {@link #reset()}.
+     */
+    private long processingStart;
+
+    /**
+     * The system time when {@link #done()} was called or -1 while processing is in progress.
+     */
+    private long processingEnd;
+
+    /**
+     * The list of tracking entries.
+     */
+    private final List<TrackingEntry> entries = new ArrayList<TrackingEntry>();
+    /**
+     * Map of named timers indexed by timer name storing the system time of
+     * start of the respective timer.
+     */
+    private final Map<String, Long> namedTimerEntries = new HashMap<String, Long>();
+
+    private final FastMessageFormat messageFormat = new FastMessageFormat();
+
+    /**
+     * Creates a new request progress tracker.
+     */
+    public RequestProgressTrackerImpl() {
+        this(null);
+    }
+
+    /**
+     * Creates a new request progress tracker and logs initial messages about the supplied request.
+     *
+     * @param request the request
+     */
+    public RequestProgressTrackerImpl(final HttpServletRequest request) {
+        reset();
+        if (request != null) {
+            log("Method={0}, PathInfo={1}", request.getMethod(), request.getPathInfo());
+        }
+    }
+
+    /**
+     * Resets this timer by removing all current entries and timers and adds an
+     * initial timer entry
+     */
+    public void reset() {
+        // remove all entries
+        entries.clear();
+        namedTimerEntries.clear();
+
+        // enter initial messages
+        processingStart = startTimerInternal(REQUEST_PROCESSING_TIMER);
+        processingEnd = -1;
+
+        entries.add(new TrackingEntry(COMMENT_PREFIX + "timer_end format is " + TIMER_END_FORMAT));
+    }
+
+    /**
+     * @see org.apache.sling.api.request.RequestProgressTracker#getMessages()
+     */
+    public Iterator<String> getMessages() {
+        return new Iterator<String>() {
+            private final Iterator<TrackingEntry> entryIter = entries.iterator();
+
+            public boolean hasNext() {
+                return entryIter.hasNext();
+            }
+
+            public String next() {
+                // throws NoSuchElementException if no entries any more
+                final TrackingEntry entry = entryIter.next();
+                final long offset = entry.getTimeStamp() - getTimeStamp();
+                return formatMessage(offset, entry.getMessage());
+            }
+
+            public void remove() {
+                throw new UnsupportedOperationException("remove");
+            }
+        };
+    }
+
+    private String formatMessage(long offset, String message) {
+        // Set exact length to avoid array copies within StringBuilder
+        final StringBuilder sb = new StringBuilder(PADDING_WIDTH + 1 +  message.length() + 1);
+        final String offsetStr = Long.toString(offset / 1000);
+        for (int i = PADDING_WIDTH - offsetStr.length(); i > 0; i--) {
+            sb.append(' ');
+        }
+        sb.append(offsetStr).append(' ').append(message).append('\n');
+        return sb.toString();
+    }
+
+    /**
+     * Dumps the process timer entries to the given writer, one entry per line.
+     * See the class comments for the rough format of each message line.
+     */
+    public void dump(final PrintWriter writer) {
+        logTimer(REQUEST_PROCESSING_TIMER,
+            "Dumping SlingRequestProgressTracker Entries");
+
+        final StringBuilder sb = new StringBuilder();
+        final Iterator<String> messages = getMessages();
+        while (messages.hasNext()) {
+            sb.append(messages.next());
+        }
+        writer.print(sb.toString());
+    }
+
+    /** Creates an entry with the given message. */
     public void log(String message) {
-        // does nothing in this mock class
+        entries.add(new TrackingEntry(LOG_PREFIX + message));
     }
 
-    @Override
+    /** Creates an entry with the given entry tag and message */
     public void log(String format, Object... args) {
-        // does nothing in this mock class
+        String message = messageFormat.format(format, args);
+        entries.add(new TrackingEntry(LOG_PREFIX + message));
     }
 
-    @Override
-    public void startTimer(String timerName) {
-        // does nothing in this mock class
+    /**
+     * Starts a named timer. If a timer of the same name already exists, it is
+     * reset to the current time.
+     */
+    public void startTimer(String name) {
+        startTimerInternal(name);
     }
 
-    @Override
-    public void logTimer(String timerName) {
-        // does nothing in this mock class
+    /**
+     * Start the named timer and returns the start time in milliseconds.
+     * Logs a message with format
+     * <pre>
+     * TIMER_START{<name>} <optional message>
+     * </pre>
+     */
+    private long startTimerInternal(String name) {
+        long timer = System.nanoTime();
+        namedTimerEntries.put(name, timer);
+        entries.add(new TrackingEntry(timer, "TIMER_START{" + name + "}"));
+        return timer;
     }
 
-    @Override
-    public void logTimer(String timerName, String format, Object... args) {
-        // does nothing in this mock class
+    /**
+     * Log a timer entry, including start, end and elapsed time.
+     */
+    public void logTimer(String name) {
+        if (namedTimerEntries.containsKey(name)) {
+            logTimerInternal(name, null, namedTimerEntries.get(name));
+        }
     }
 
-    @Override
-    public Iterator<String> getMessages() {
-        return Collections.emptyIterator();
+    /**
+     * Log a timer entry, including start, end and elapsed time.
+     */
+    public void logTimer(String name, String format, Object... args) {
+        if (namedTimerEntries.containsKey(name)) {
+            logTimerInternal(name, messageFormat.format(format, args), namedTimerEntries.get(name));
+        }
     }
 
-    @Override
-    public void dump(PrintWriter writer) {
-        // does nothing in this mock class
+    /**
+     * Log a timer entry, including start, end and elapsed time using TIMER_END_FORMAT
+     */
+    private void logTimerInternal(String name, String msg, long startTime) {
+        final StringBuilder sb = new StringBuilder();
+        sb.append("TIMER_END{");
+        sb.append((System.nanoTime() - startTime) / 1000);
+        sb.append(',');
+        sb.append(name);
+        sb.append('}');
+        if(msg != null) {
+            sb.append(' ');
+            sb.append(msg);
+        }
+        entries.add(new TrackingEntry(sb.toString()));
     }
 
-    @Override
     public void done() {
-        // does nothing in this mock class
+        if(processingEnd != -1) return;
+        logTimer(REQUEST_PROCESSING_TIMER, REQUEST_PROCESSING_TIMER);
+        processingEnd = System.nanoTime();
+    }
+
+    private long getTimeStamp() {
+        return processingStart;
+    }
+
+    public long getDuration() {
+        if (processingEnd != -1) {
+            return processingEnd - processingStart;
+        }
+        return System.nanoTime() - processingStart;
+    }
+
+    /** Process tracker entry keeping timestamp, tag and message */
+    private static class TrackingEntry {
+
+        // creation time stamp
+        private final long timeStamp;
+
+        // tracking message
+        private final String message;
+
+        TrackingEntry(String message) {
+            this.timeStamp = System.nanoTime();
+            this.message = message;
+        }
+
+        TrackingEntry(long timeStamp, String message) {
+            this.timeStamp = timeStamp;
+            this.message = message;
+        }
+
+        long getTimeStamp() {
+            return timeStamp;
+        }
+
+        String getMessage() {
+            return message;
+        }
     }
 }
diff --git a/src/main/java/org/apache/sling/api/request/builder/impl/SlingHttpServletRequestImpl.java b/src/main/java/org/apache/sling/api/request/builder/impl/SlingHttpServletRequestImpl.java
index cdfa5c5..dcb1314 100644
--- a/src/main/java/org/apache/sling/api/request/builder/impl/SlingHttpServletRequestImpl.java
+++ b/src/main/java/org/apache/sling/api/request/builder/impl/SlingHttpServletRequestImpl.java
@@ -63,6 +63,7 @@ import org.apache.sling.api.request.RequestParameter;
 import org.apache.sling.api.request.RequestParameterMap;
 import org.apache.sling.api.request.RequestPathInfo;
 import org.apache.sling.api.request.RequestProgressTracker;
+import org.apache.sling.api.request.builder.Builders;
 import org.apache.sling.api.request.builder.SlingHttpServletRequestBuilder;
 import org.apache.sling.api.resource.Resource;
 import org.apache.sling.api.resource.ResourceResolver;
@@ -146,7 +147,7 @@ public class SlingHttpServletRequestImpl extends SlingAdaptable
     private final Map<String, Cookie> cookies = new LinkedHashMap<>();
 
     /** Request progress tracker */
-    private final RequestProgressTracker progressTracker = new RequestProgressTrackerImpl();
+    private RequestProgressTracker progressTracker;
 
     private HttpServletRequest sessionProvider;
 
@@ -303,6 +304,12 @@ public class SlingHttpServletRequestImpl extends SlingAdaptable
     }
 
     @Override
+    public @NotNull SlingHttpServletRequestBuilder withRequestProgressTracker(@NotNull RequestProgressTracker tracker) {
+        this.progressTracker = tracker;
+        return this;
+    }
+
+    @Override
     public @NotNull SlingHttpServletRequest build() {
         this.checkLocked();
         this.locked = true;
@@ -322,6 +329,15 @@ public class SlingHttpServletRequestImpl extends SlingAdaptable
         if (this.body == null ) {
             this.body = "";
         }
+        if (this.progressTracker == null) {
+            // if attributes are shared with a Sling request, then the progress tracker is available from there
+            final Object attrTracker = this.getAttribute(RequestProgressTracker.class.getName());
+            if ( attrTracker instanceof RequestProgressTracker) {
+                this.progressTracker = (RequestProgressTracker)attrTracker;
+            } else {
+                this.progressTracker = Builders.newRequestProgressTracker();
+            }
+        }
         return this;
     }
 
diff --git a/src/main/java/org/apache/sling/api/request/builder/package-info.java b/src/main/java/org/apache/sling/api/request/builder/package-info.java
index 11251e6..645ded3 100644
--- a/src/main/java/org/apache/sling/api/request/builder/package-info.java
+++ b/src/main/java/org/apache/sling/api/request/builder/package-info.java
@@ -16,5 +16,5 @@
  * specific language governing permissions and limitations
  * under the License.
  */
-@org.osgi.annotation.versioning.Version("1.0")
+@org.osgi.annotation.versioning.Version("1.1")
 package org.apache.sling.api.request.builder;
diff --git a/src/test/java/org/apache/sling/api/request/builder/BuildersTest.java b/src/test/java/org/apache/sling/api/request/builder/BuildersTest.java
index 35c0571..3a813d4 100644
--- a/src/test/java/org/apache/sling/api/request/builder/BuildersTest.java
+++ b/src/test/java/org/apache/sling/api/request/builder/BuildersTest.java
@@ -55,6 +55,8 @@ public class BuildersTest {
         assertArrayEquals(new String[] {"tidy", "json"}, req.getRequestPathInfo().getSelectors());
         assertNull(req.getRequestPathInfo().getSuffix());
         assertNull(req.getRequestPathInfo().getSuffixResource());
+
+        assertNotNull(req.getRequestProgressTracker());
     }
 
     @Test
@@ -63,4 +65,9 @@ public class BuildersTest {
         final SlingHttpServletResponseResult result = builder.build();
         assertNotNull(result);        
     }
+
+    @Test
+    public void createRequestProgressTracker() {
+        assertNotNull(Builders.newRequestProgressTracker());
+    }
 }
diff --git a/src/test/java/org/apache/sling/api/request/builder/impl/FastMessageFormatTest.java b/src/test/java/org/apache/sling/api/request/builder/impl/FastMessageFormatTest.java
new file mode 100644
index 0000000..22b1803
--- /dev/null
+++ b/src/test/java/org/apache/sling/api/request/builder/impl/FastMessageFormatTest.java
@@ -0,0 +1,81 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You 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 org.apache.sling.api.request.builder.impl;
+
+import org.junit.Test;
+
+import java.text.MessageFormat;
+import java.util.Arrays;
+import java.util.Calendar;
+import java.util.Date;
+
+import static org.junit.Assert.assertEquals;
+
+public class FastMessageFormatTest {
+
+    @Test
+    public void testFormat() {
+        FormatTest[] tests = {
+                // Data types
+                new FormatTest("{0}", 1),
+                new FormatTest("{0}", Integer.MAX_VALUE),
+                new FormatTest("{0}", Long.MAX_VALUE),
+                new FormatTest("{0}", Math.PI),
+                new FormatTest("{0}", 123456.123456),
+                new FormatTest("{0}", Float.MAX_VALUE),
+                new FormatTest("{0}", new Date()),
+                new FormatTest("{0}", Calendar.getInstance()),
+                new FormatTest("{0}", true),
+                new FormatTest("{0}", false),
+                new FormatTest("{0}", new int[] {1,2,3}),
+                new FormatTest("{0}", (Object) new Integer[] {1,2,3}),
+                new FormatTest("{0}", Arrays.asList(1, 2, 3)),
+                new FormatTest("{0}", "text"),
+
+                // Patterns
+                new FormatTest("{0}{0}", 1, 2),
+                new FormatTest("a{0}b{1}c", 1, 2),
+                new FormatTest("a{0}b{1}c{2}d", 1, 2, 3),
+                new FormatTest("a{0}bb{1}ccc{2}dddd", 10, 20, 30),
+                new FormatTest("c{1}b{0}a", 1, 2),
+                new FormatTest("c{1}b{0}a{1}c", 1, 2),
+
+                // Type/style
+                new FormatTest("c{0,number,#.##}b{0}a{1}c", 1, 2),
+                new FormatTest("{0,number,#.##}", 1.2345),
+
+                // Escaping
+                new FormatTest("'{0}'", 1)
+        };
+
+        FastMessageFormat fastMessageFormat = new FastMessageFormat();
+        for (FormatTest test : tests) {
+            String expected = MessageFormat.format(test.pattern, test.args);
+            String actual = fastMessageFormat.format(test.pattern, test.args);
+            assertEquals(expected, actual);
+        }
+    }
+
+    private static class FormatTest {
+        final String pattern;
+        final Object[] args;
+        public FormatTest(String pattern, Object... args) {
+            this.pattern = pattern;
+            this.args = args;
+        }
+    }
+}
diff --git a/src/test/java/org/apache/sling/api/request/builder/impl/RequestProgressTrackerImplTest.java b/src/test/java/org/apache/sling/api/request/builder/impl/RequestProgressTrackerImplTest.java
index c757ba2..3a4aeab 100644
--- a/src/test/java/org/apache/sling/api/request/builder/impl/RequestProgressTrackerImplTest.java
+++ b/src/test/java/org/apache/sling/api/request/builder/impl/RequestProgressTrackerImplTest.java
@@ -1,42 +1,136 @@
 /*
- * Licensed to the Apache Software Foundation (ASF) under one
- * or more contributor license agreements.  See the NOTICE file
- * distributed with this work for additional information
- * regarding copyright ownership.  The ASF licenses this file
- * to you 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
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You 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
+ *      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.
+ * 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 org.apache.sling.api.request.builder.impl;
 
-import static org.junit.Assert.assertFalse;
+import static org.junit.Assert.assertTrue;
+import static org.junit.Assert.fail;
+import static org.junit.Assert.assertEquals;
 
+import java.io.BufferedReader;
+import java.io.IOException;
 import java.io.PrintWriter;
+import java.io.StringReader;
 import java.io.StringWriter;
+import java.util.Iterator;
 
+import org.junit.Before;
 import org.junit.Test;
 
 public class RequestProgressTrackerImplTest {
 
-    @Test public void testTracker() {
-        final RequestProgressTrackerImpl tracker = new RequestProgressTrackerImpl();
-        // this test basically checks that all methods are callable
-        tracker.log("message");
-        tracker.log("%s", "message");
+    private RequestProgressTrackerImpl tracker;
+
+    @Before
+    public void setup() {
+        tracker = new RequestProgressTrackerImpl();
+    }
+
+    private void addTestData() {
         tracker.startTimer("foo");
+        tracker.log("one {0}, two {1}, three {2}", "eins", "zwei", "drei");
+        tracker.startTimer("bar");
+        tracker.logTimer("bar");
         tracker.logTimer("foo");
-        tracker.logTimer("foo", "%s", "msg");
-        assertFalse(tracker.getMessages().hasNext());
-        tracker.dump(new PrintWriter(new StringWriter()));
         tracker.done();
     }
+
+    @Test
+    public void messageFormatting() {
+        final String[] expected = {
+                "TIMER_START{Request Processing}\n",
+                "COMMENT timer_end format is {<elapsed microseconds>,<timer name>} <optional message>\n",
+                "TIMER_START{foo}\n",
+                "LOG one eins, two zwei, three drei\n",
+                "TIMER_START{bar}\n",
+                "TIMER_END{?,bar}\n",
+                "TIMER_END{?,foo}\n",
+                "TIMER_END{?,Request Processing} Request Processing\n"
+        };
+
+        addTestData();
+        final Iterator<String> messages = tracker.getMessages();
+        int messageCounter = 0;
+        while (messages.hasNext()) {
+            final String m = messages.next();
+            final String e = expected[messageCounter++];
+            if (e.startsWith("TIMER_END{")) {
+                // account for the counter in the string
+                assertEquals(substringAfter(e, ','), substringAfter(m, ','));
+            } else {
+                // strip off counter
+                assertEquals(e, m.substring(8));
+            }
+        }
+
+        assertEquals(expected.length, messageCounter);
+    }
+
+    @Test
+    public void dump() throws IOException {
+        addTestData();
+        final StringWriter w = new StringWriter();
+        tracker.dump(new PrintWriter(w));
+        w.flush();
+        final String result = w.toString();
+
+        final String [] expected = {
+                "TIMER_START{Request Processing}",
+                "TIMER_START{foo}",
+                "Dumping SlingRequestProgressTracker Entries"
+        };
+        for(String exp : expected) {
+            if(!result.contains(exp)) {
+                fail("Expected result to contain [" + exp + "] but was [" + result + "]");
+            }
+        }
+
+        int lineCount = 0;
+        final BufferedReader br = new BufferedReader(new StringReader(result));
+        while(br.readLine() != null) {
+            lineCount++;
+        }
+        assertEquals(9, lineCount);
+    }
+
+    @Test
+    public void duration() throws InterruptedException {
+        Thread.sleep(50);
+        tracker.log("after the wait");
+        assertTrue(tracker.getDuration() >= 50);
+    }
+
+    @Test
+    public void durationWithDone() throws InterruptedException {
+        Thread.sleep(25);
+        tracker.done();
+        final long d = tracker.getDuration();
+        assertTrue(d >= 25);
+        Thread.sleep(25);
+        tracker.log("Some more stuff");
+        assertEquals(d, tracker.getDuration());
+    }
+
+    @Test(expected=UnsupportedOperationException.class)
+    public void removeFails() {
+        tracker.getMessages().remove();
+    }
+
+    private String substringAfter(String string, char ch) {
+        final int pos = string.indexOf(ch);
+        return string.substring(pos);
+    }
 }
diff --git a/src/test/java/org/apache/sling/api/request/builder/impl/SlingHttpServletRequestImplTest.java b/src/test/java/org/apache/sling/api/request/builder/impl/SlingHttpServletRequestImplTest.java
index 5cf1e41..7d84954 100644
--- a/src/test/java/org/apache/sling/api/request/builder/impl/SlingHttpServletRequestImplTest.java
+++ b/src/test/java/org/apache/sling/api/request/builder/impl/SlingHttpServletRequestImplTest.java
@@ -43,6 +43,8 @@ import javax.servlet.http.HttpSession;
 import org.apache.sling.api.SlingHttpServletRequest;
 import org.apache.sling.api.request.RequestDispatcherOptions;
 import org.apache.sling.api.request.RequestParameter;
+import org.apache.sling.api.request.RequestProgressTracker;
+import org.apache.sling.api.request.builder.Builders;
 import org.apache.sling.api.resource.Resource;
 import org.apache.sling.api.resource.ResourceResolver;
 import org.junit.Before;
@@ -404,11 +406,27 @@ public class SlingHttpServletRequestImplTest {
         assertEquals(Collections.singletonList(null), Collections.list(req.getResponseContentTypes()));
     }
 
-    @Test public void testGetRequestProgressTracker() {
+    @Test public void testNewGetRequestProgressTracker() {
         req.build();
         assertNotNull(req.getRequestProgressTracker());
     }
 
+    @Test public void testProvidedGetRequestProgressTracker() {
+        final RequestProgressTracker t = Builders.newRequestProgressTracker();
+        req.withRequestProgressTracker(t).build();
+        assertSame(t, req.getRequestProgressTracker());
+    }
+
+    @Test public void testProvidedByAttributesGetRequestProgressTracker() {
+        // build a request with a tracker set in an attribute first
+        final SlingHttpServletRequest orig = new SlingHttpServletRequestImpl(this.resource);
+        final RequestProgressTracker t = Builders.newRequestProgressTracker();
+        orig.setAttribute(RequestProgressTracker.class.getName(), t);
+
+        req.useAttributesFrom(orig).build();
+        assertSame(t, req.getRequestProgressTracker());
+    }
+
     @Test public void testDefaultServletContext() {
         req.build();
         final ServletContext ctx = req.getServletContext();