This is an automated email from the ASF dual-hosted git repository. danhaywood pushed a commit to branch CAUSEWAY-3751 in repository https://gitbox.apache.org/repos/asf/causeway.git
commit aa0f9642357dc812c99e6fde8fe8069e6a4de1d8 Author: Dan Haywood <[email protected]> AuthorDate: Tue Jun 25 15:02:10 2024 +0200 CAUSEWAY-3751: splits PageRenderLogger into 3 also include timings, and user --- ...sewayModuleApplibChangeAndExecutionLoggers.java | 10 ++- ...Logger.java => PageRenderCollectionLogger.java} | 57 ++++---------- ...gger.java => PageRenderDomainObjectLogger.java} | 72 ++++-------------- ...enderLogger.java => PageRenderValueLogger.java} | 86 +++++----------------- .../applib/services/publishing/log/Timing.java | 13 ++++ 5 files changed, 71 insertions(+), 167 deletions(-) diff --git a/api/applib/src/main/java/org/apache/causeway/applib/CausewayModuleApplibChangeAndExecutionLoggers.java b/api/applib/src/main/java/org/apache/causeway/applib/CausewayModuleApplibChangeAndExecutionLoggers.java index 28f5bac7c5..9c140ef07c 100644 --- a/api/applib/src/main/java/org/apache/causeway/applib/CausewayModuleApplibChangeAndExecutionLoggers.java +++ b/api/applib/src/main/java/org/apache/causeway/applib/CausewayModuleApplibChangeAndExecutionLoggers.java @@ -18,6 +18,10 @@ */ package org.apache.causeway.applib; +import org.apache.causeway.applib.services.publishing.log.PageRenderCollectionLogger; + +import org.apache.causeway.applib.services.publishing.log.PageRenderValueLogger; + import org.springframework.context.annotation.Configuration; import org.springframework.context.annotation.Import; @@ -25,7 +29,7 @@ import org.apache.causeway.applib.services.publishing.log.CommandLogger; import org.apache.causeway.applib.services.publishing.log.EntityChangesLogger; import org.apache.causeway.applib.services.publishing.log.EntityPropertyChangeLogger; import org.apache.causeway.applib.services.publishing.log.ExecutionLogger; -import org.apache.causeway.applib.services.publishing.log.PageRenderLogger; +import org.apache.causeway.applib.services.publishing.log.PageRenderDomainObjectLogger; /** * Registers logging subscribers for the command/execution/change publishing subsystem. @@ -42,7 +46,9 @@ import org.apache.causeway.applib.services.publishing.log.PageRenderLogger; EntityChangesLogger.class, EntityPropertyChangeLogger.class, ExecutionLogger.class, - PageRenderLogger.class, + PageRenderDomainObjectLogger.class, + PageRenderCollectionLogger.class, + PageRenderValueLogger.class, }) public class CausewayModuleApplibChangeAndExecutionLoggers { diff --git a/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderLogger.java b/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderCollectionLogger.java similarity index 66% copy from api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderLogger.java copy to api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderCollectionLogger.java index 40d91f628b..f0b9ef500a 100644 --- a/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderLogger.java +++ b/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderCollectionLogger.java @@ -27,8 +27,6 @@ import javax.annotation.Priority; import javax.inject.Inject; import javax.inject.Named; -import org.apache.causeway.applib.services.metrics.MetricsService; - import org.springframework.beans.factory.annotation.Qualifier; import org.springframework.lang.Nullable; import org.springframework.stereotype.Service; @@ -36,7 +34,9 @@ import org.springframework.stereotype.Service; import org.apache.causeway.applib.CausewayModuleApplib; import org.apache.causeway.applib.annotation.PriorityPrecedence; import org.apache.causeway.applib.services.bookmark.Bookmark; +import org.apache.causeway.applib.services.metrics.MetricsService; import org.apache.causeway.applib.services.publishing.spi.PageRenderSubscriber; +import org.apache.causeway.applib.services.user.UserService; import org.apache.causeway.commons.internal.base._NullSafe; import lombok.RequiredArgsConstructor; @@ -45,86 +45,59 @@ import lombok.extern.log4j.Log4j2; /** * Simple implementation of {@link PageRenderSubscriber} that just - * logs to a debug log. + * logs the rendering of any collections to a debug log. * - * @since 2.0 {@index} + * @since 2.1 {@index} */ @Service -@Named(PageRenderLogger.LOGICAL_TYPE_NAME) +@Named(PageRenderCollectionLogger.LOGICAL_TYPE_NAME) @Priority(PriorityPrecedence.LATE) @Qualifier("Logging") @RequiredArgsConstructor(onConstructor_ = {@Inject}) @Log4j2 -public class PageRenderLogger implements PageRenderSubscriber { +public class PageRenderCollectionLogger implements PageRenderSubscriber { private final MetricsService metricsService; + private final UserService userService; - static final String LOGICAL_TYPE_NAME = CausewayModuleApplib.NAMESPACE + ".PageRenderLogger"; + static final String LOGICAL_TYPE_NAME = CausewayModuleApplib.NAMESPACE + ".PageRenderCollectionLogger"; @Override public boolean isEnabled() { return log.isDebugEnabled(); } - @Override - public void onRenderingDomainObject(final Bookmark bookmark) { - if(log.isDebugEnabled()) { - log.debug("rendering object: [ {} ]", doubleQuoted(bookmark.stringify())); - } - } + + private static ThreadLocal<Timing> timings = ThreadLocal.withInitial(Timing::new); @Override public void onRenderingCollection(final Supplier<List<Bookmark>> bookmarkSupplier) { - final var bookmarksStringified = bookmarksStringified(bookmarkSupplier); - if (log.isDebugEnabled()) { - log.debug("rendering collection: [ {} ]", bookmarksStringified); - } - } - - - @Override - public void onRenderingValue(final Object value) { - if(log.isDebugEnabled()) { - log.debug("rendering value: [ {} ]", doubleQuoted(value)); + log.debug("rendering collection: [ {} ] user: {}", bookmarksStringified, userService.currentUserNameElseNobody()); } + timings.set(new Timing()); } - @Override - public void onRenderedDomainObject(final Bookmark bookmark) { - if(log.isDebugEnabled()) { - // until @ActionLayout#redirectPolicy is reintroduced (if it ever is), there's no point in querying for the numberEntitiesDirtied, - // bceause (for Wicket viewer at least), the rendering is in a separate request to any modifying action. - log.debug("rendered object: [ {} ] numEntitiesLoaded: {}", doubleQuoted(bookmark.stringify()), metricsService.numberEntitiesLoaded()); - } - } @Override public void onRenderedCollection(final Supplier<List<Bookmark>> bookmarkSupplier) { - final var bookmarksStringified = bookmarksStringified(bookmarkSupplier); + val timing = timings.get(); if (log.isDebugEnabled()) { - log.debug("rendered collection: [ {} ]", bookmarksStringified); + log.debug("rendered collection: [ {} ] user: {} took: {}ms", bookmarksStringified, userService.currentUserNameElseNobody(), timing.took()); } } - @Override - public void onRenderedValue(final Object value) { - if(log.isDebugEnabled()) { - log.debug("rendered value: [ {} ]", doubleQuoted(value)); - } - } - // -- HELPER private static String bookmarksStringified(Supplier<List<Bookmark>> bookmarkSupplier) { return _NullSafe.stream(bookmarkSupplier.get()) .filter(Objects::nonNull) .map(Bookmark::stringify) - .map(PageRenderLogger::doubleQuoted) + .map(PageRenderCollectionLogger::doubleQuoted) .collect(Collectors.joining(", ")); } diff --git a/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderLogger.java b/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderDomainObjectLogger.java similarity index 56% copy from api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderLogger.java copy to api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderDomainObjectLogger.java index 40d91f628b..49d2e4ca34 100644 --- a/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderLogger.java +++ b/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderDomainObjectLogger.java @@ -29,6 +29,8 @@ import javax.inject.Named; import org.apache.causeway.applib.services.metrics.MetricsService; +import org.apache.causeway.applib.services.user.UserService; + import org.springframework.beans.factory.annotation.Qualifier; import org.springframework.lang.Nullable; import org.springframework.stereotype.Service; @@ -40,95 +42,53 @@ import org.apache.causeway.applib.services.publishing.spi.PageRenderSubscriber; import org.apache.causeway.commons.internal.base._NullSafe; import lombok.RequiredArgsConstructor; -import lombok.val; import lombok.extern.log4j.Log4j2; +import lombok.val; /** * Simple implementation of {@link PageRenderSubscriber} that just * logs to a debug log. * - * @since 2.0 {@index} + * @since 2.1 {@index} */ @Service -@Named(PageRenderLogger.LOGICAL_TYPE_NAME) +@Named(PageRenderDomainObjectLogger.LOGICAL_TYPE_NAME) @Priority(PriorityPrecedence.LATE) @Qualifier("Logging") @RequiredArgsConstructor(onConstructor_ = {@Inject}) @Log4j2 -public class PageRenderLogger implements PageRenderSubscriber { +public class PageRenderDomainObjectLogger implements PageRenderSubscriber { private final MetricsService metricsService; + private final UserService userService; - static final String LOGICAL_TYPE_NAME = CausewayModuleApplib.NAMESPACE + ".PageRenderLogger"; + static final String LOGICAL_TYPE_NAME = CausewayModuleApplib.NAMESPACE + ".PageRenderDomainObjectLogger"; @Override public boolean isEnabled() { return log.isDebugEnabled(); } - @Override - public void onRenderingDomainObject(final Bookmark bookmark) { - if(log.isDebugEnabled()) { - log.debug("rendering object: [ {} ]", doubleQuoted(bookmark.stringify())); - } - } - - @Override - public void onRenderingCollection(final Supplier<List<Bookmark>> bookmarkSupplier) { - - final var bookmarksStringified = bookmarksStringified(bookmarkSupplier); - - if (log.isDebugEnabled()) { - log.debug("rendering collection: [ {} ]", bookmarksStringified); - } - } + private static ThreadLocal<Timing> timings = ThreadLocal.withInitial(Timing::new); @Override - public void onRenderingValue(final Object value) { + public void onRenderingDomainObject(final Bookmark bookmark) { if(log.isDebugEnabled()) { - log.debug("rendering value: [ {} ]", doubleQuoted(value)); + log.debug("rendering object: [ \"{}\" ] user: {}", bookmark.stringify(), userService.currentUserNameElseNobody()); } + timings.set(new Timing()); } @Override public void onRenderedDomainObject(final Bookmark bookmark) { - if(log.isDebugEnabled()) { + if(log.isInfoEnabled()) { + val timing = timings.get(); // until @ActionLayout#redirectPolicy is reintroduced (if it ever is), there's no point in querying for the numberEntitiesDirtied, - // bceause (for Wicket viewer at least), the rendering is in a separate request to any modifying action. - log.debug("rendered object: [ {} ] numEntitiesLoaded: {}", doubleQuoted(bookmark.stringify()), metricsService.numberEntitiesLoaded()); - } - } - - @Override - public void onRenderedCollection(final Supplier<List<Bookmark>> bookmarkSupplier) { - - final var bookmarksStringified = bookmarksStringified(bookmarkSupplier); - - if (log.isDebugEnabled()) { - log.debug("rendered collection: [ {} ]", bookmarksStringified); + // because (for Wicket viewer at least), the rendering is in a separate request to any modifying action. + log.info("rendered object: [ \"{}\" ] user: {} took: {}ms numEntitiesLoaded: {}", bookmark.stringify(), userService.currentUserNameElseNobody(), timing.took(), metricsService.numberEntitiesLoaded()); } } - @Override - public void onRenderedValue(final Object value) { - if(log.isDebugEnabled()) { - log.debug("rendered value: [ {} ]", doubleQuoted(value)); - } - } - - // -- HELPER - - private static String bookmarksStringified(Supplier<List<Bookmark>> bookmarkSupplier) { - return _NullSafe.stream(bookmarkSupplier.get()) - .filter(Objects::nonNull) - .map(Bookmark::stringify) - .map(PageRenderLogger::doubleQuoted) - .collect(Collectors.joining(", ")); - } - - private static String doubleQuoted(final @Nullable Object obj) { - return "\"" + obj + "\""; - } } diff --git a/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderLogger.java b/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderValueLogger.java similarity index 51% rename from api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderLogger.java rename to api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderValueLogger.java index 40d91f628b..c6d1d94503 100644 --- a/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderLogger.java +++ b/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/PageRenderValueLogger.java @@ -18,6 +18,10 @@ */ package org.apache.causeway.applib.services.publishing.log; +import lombok.RequiredArgsConstructor; +import lombok.extern.log4j.Log4j2; +import lombok.val; + import java.util.List; import java.util.Objects; import java.util.function.Supplier; @@ -27,108 +31,56 @@ import javax.annotation.Priority; import javax.inject.Inject; import javax.inject.Named; -import org.apache.causeway.applib.services.metrics.MetricsService; - -import org.springframework.beans.factory.annotation.Qualifier; -import org.springframework.lang.Nullable; -import org.springframework.stereotype.Service; - import org.apache.causeway.applib.CausewayModuleApplib; import org.apache.causeway.applib.annotation.PriorityPrecedence; import org.apache.causeway.applib.services.bookmark.Bookmark; +import org.apache.causeway.applib.services.metrics.MetricsService; import org.apache.causeway.applib.services.publishing.spi.PageRenderSubscriber; +import org.apache.causeway.applib.services.user.UserService; import org.apache.causeway.commons.internal.base._NullSafe; -import lombok.RequiredArgsConstructor; -import lombok.val; -import lombok.extern.log4j.Log4j2; +import org.springframework.beans.factory.annotation.Qualifier; +import org.springframework.lang.Nullable; +import org.springframework.stereotype.Service; /** * Simple implementation of {@link PageRenderSubscriber} that just * logs to a debug log. * - * @since 2.0 {@index} + * @since 2.1 {@index} */ @Service -@Named(PageRenderLogger.LOGICAL_TYPE_NAME) +@Named(PageRenderValueLogger.LOGICAL_TYPE_NAME) @Priority(PriorityPrecedence.LATE) @Qualifier("Logging") @RequiredArgsConstructor(onConstructor_ = {@Inject}) @Log4j2 -public class PageRenderLogger implements PageRenderSubscriber { +public class PageRenderValueLogger implements PageRenderSubscriber { - private final MetricsService metricsService; + private final UserService userService; - static final String LOGICAL_TYPE_NAME = CausewayModuleApplib.NAMESPACE + ".PageRenderLogger"; + static final String LOGICAL_TYPE_NAME = CausewayModuleApplib.NAMESPACE + ".PageRenderValueLogger"; @Override public boolean isEnabled() { return log.isDebugEnabled(); } - @Override - public void onRenderingDomainObject(final Bookmark bookmark) { - if(log.isDebugEnabled()) { - log.debug("rendering object: [ {} ]", doubleQuoted(bookmark.stringify())); - } - } - - @Override - public void onRenderingCollection(final Supplier<List<Bookmark>> bookmarkSupplier) { - - final var bookmarksStringified = bookmarksStringified(bookmarkSupplier); - - if (log.isDebugEnabled()) { - log.debug("rendering collection: [ {} ]", bookmarksStringified); - } - } - + private static ThreadLocal<Timing> timings = ThreadLocal.withInitial(Timing::new); @Override public void onRenderingValue(final Object value) { if(log.isDebugEnabled()) { - log.debug("rendering value: [ {} ]", doubleQuoted(value)); - } - } - - @Override - public void onRenderedDomainObject(final Bookmark bookmark) { - if(log.isDebugEnabled()) { - // until @ActionLayout#redirectPolicy is reintroduced (if it ever is), there's no point in querying for the numberEntitiesDirtied, - // bceause (for Wicket viewer at least), the rendering is in a separate request to any modifying action. - log.debug("rendered object: [ {} ] numEntitiesLoaded: {}", doubleQuoted(bookmark.stringify()), metricsService.numberEntitiesLoaded()); - } - } - - @Override - public void onRenderedCollection(final Supplier<List<Bookmark>> bookmarkSupplier) { - - final var bookmarksStringified = bookmarksStringified(bookmarkSupplier); - - if (log.isDebugEnabled()) { - log.debug("rendered collection: [ {} ]", bookmarksStringified); + log.debug("rendering value: [ \"{}\" ] user: {}", value, userService.currentUserNameElseNobody()); } + timings.set(new Timing()); } - @Override public void onRenderedValue(final Object value) { if(log.isDebugEnabled()) { - log.debug("rendered value: [ {} ]", doubleQuoted(value)); + val timing = timings.get(); + log.debug("rendered value: [ \"{}\" ] user: {} took: {}ms", value, userService.currentUserNameElseNobody(), timing.took()); } } - - // -- HELPER - - private static String bookmarksStringified(Supplier<List<Bookmark>> bookmarkSupplier) { - return _NullSafe.stream(bookmarkSupplier.get()) - .filter(Objects::nonNull) - .map(Bookmark::stringify) - .map(PageRenderLogger::doubleQuoted) - .collect(Collectors.joining(", ")); - } - - private static String doubleQuoted(final @Nullable Object obj) { - return "\"" + obj + "\""; - } } diff --git a/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/Timing.java b/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/Timing.java new file mode 100644 index 0000000000..38594a047a --- /dev/null +++ b/api/applib/src/main/java/org/apache/causeway/applib/services/publishing/log/Timing.java @@ -0,0 +1,13 @@ +package org.apache.causeway.applib.services.publishing.log; + +class Timing { + private final long startTime; + + Timing() { + this.startTime = System.currentTimeMillis(); + } + + long took() { + return System.currentTimeMillis() - startTime; + } +}
