From 8b2feb580c4ad9ab3bd58f061f8ec5e7eadc657f Mon Sep 17 00:00:00 2001 From: Marco Collovati Date: Thu, 18 Apr 2024 11:45:35 +0200 Subject: [PATCH 1/5] fix: improve serialization tracking memory usage Improves memory usage and performance during serialization by: - reusing JDK DebugTraceInfoStack strings insted of joining them into a single one - preventing trace info to be serialized - inspect for injectable transient only application objects - prevent writing tracking metadata twice on the target stream - clear temporary output stream byte array once data is copied to the target stream Part of #128 --- ...TransientInjectableObjectOutputStream.java | 55 ++++++++++++++----- .../serialization/debug/Job.java | 31 +++++++---- .../serialization/debug/Track.java | 11 ++-- 3 files changed, 69 insertions(+), 28 deletions(-) diff --git a/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/TransientInjectableObjectOutputStream.java b/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/TransientInjectableObjectOutputStream.java index d23aa66..bf88743 100644 --- a/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/TransientInjectableObjectOutputStream.java +++ b/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/TransientInjectableObjectOutputStream.java @@ -21,6 +21,7 @@ import java.lang.invoke.VarHandle; import java.util.ArrayList; import java.util.Arrays; +import java.util.Collections; import java.util.IdentityHashMap; import java.util.List; import java.util.Objects; @@ -59,9 +60,9 @@ * * 
  * {@code
- * new TransientInjectableObjectOutputStream(
- *      os, handler, type -> type.getPackageName().startsWith("com.vaadin.app")
- *  ).writeWithTransients(target);
+ * new TransientInjectableObjectOutputStream(os, handler,
+ *         type -> type.getPackageName().startsWith("com.vaadin.app"))
+ *         .writeWithTransients(target);
  * }
  *
* @@ -87,6 +88,7 @@ public class TransientInjectableObjectOutputStream extends ObjectOutputStream { private final VarHandle depthHandle; private final MethodHandle lookupObject; private final VarHandle debugStackInfo; + private final VarHandle debugStackInfoList; private final IdentityHashMap tracking = new IdentityHashMap<>(); private final boolean trackingEnabled; @@ -110,10 +112,12 @@ private TransientInjectableObjectOutputStream(OutputStream out, depthHandle = tryGetDepthHandle(); lookupObject = tryGetLookupObject(); debugStackInfo = tryGetDebugStackHandle(); + debugStackInfoList = tryGetDebugStackListHandle(); trackingEnabled = true; } else { depthHandle = null; debugStackInfo = null; + debugStackInfoList = null; lookupObject = null; trackingEnabled = false; } @@ -160,10 +164,12 @@ void markMetadata() { } void copy() throws IOException { - // TODO also remove metadata from the end of this stream before - // copying. wrapped.write(Arrays.copyOfRange(buf, metadataPosition + 3, count)); + count = metadataPosition; // prevents copy the metadata again at the + // end of the stream writeTo(wrapped); + count = 0; + buf = new byte[0]; } } @@ -199,7 +205,6 @@ public void writeWithTransients(Object object) throws IOException { * * @@ -233,7 +238,8 @@ protected void writeClassDescriptor(ObjectStreamClass desc) @Override protected Object replaceObject(Object obj) { obj = trackObject(obj); - if (obj != null) { + // Only application classes might need to be replaced + if (trackingMode && obj != null) { Class type = obj.getClass(); if (injectableFilter.test(type) && !inspected.containsKey(obj)) { Object original = obj; @@ -290,10 +296,10 @@ protected Object handleNotSerializable(Object obj) { } private Object trackObject(Object obj) { - if (getLogger().isTraceEnabled()) { - getLogger().trace("Serializing object {}", obj.getClass()); - } if (trackingMode && trackingEnabled && !tracking.containsKey(obj)) { + if (getLogger().isTraceEnabled()) { + getLogger().trace("Serializing object {}", obj.getClass()); + } Object original = obj; try { Track track = createTrackObject(++trackingCounter, obj); @@ -392,21 +398,44 @@ private static VarHandle tryGetDebugStackHandle() { } } + private static VarHandle tryGetDebugStackListHandle() { + try { + Class debugTraceInfoStackClass = Class + .forName("java.io.ObjectOutputStream$DebugTraceInfoStack"); + return MethodHandles + .privateLookupIn(debugTraceInfoStackClass, + MethodHandles.lookup()) + .findVarHandle(debugTraceInfoStackClass, "stack", + List.class); + } catch (Exception ex) { + getLogger().trace( + "Cannot access ObjectOutputStream.DebugTraceInfoStack.stack field.", + ex); + return null; + } + } + + @SuppressWarnings("unchecked") private Track createTrackObject(int id, Object obj) { int depth = -1; if (depthHandle != null) { depth = (int) depthHandle.get(this); } - String stackInfo = null; + List stackInfo = null; if (debugStackInfo != null) { Object stackElement = debugStackInfo.get(this); - stackInfo = (stackElement != null) ? stackElement.toString() : null; + if (stackElement != null && debugStackInfoList != null) { + stackInfo = new ArrayList<>( + (List) debugStackInfoList.get(stackElement)); + Collections.reverse(stackInfo); + } } return new Track(id, depth, stackInfo, obj); } private void trackClass(ObjectStreamClass type) { - if (inspector instanceof DebugMode && getLogger().isTraceEnabled()) { + if (trackingMode && inspector instanceof DebugMode + && getLogger().isTraceEnabled()) { String fields = Stream.of(type.getFields()) .filter(field -> !field.isPrimitive() && !Serializable.class .isAssignableFrom(field.getType())) diff --git a/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/Job.java b/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/Job.java index dafa3bd..4f427d3 100644 --- a/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/Job.java +++ b/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/Job.java @@ -102,12 +102,11 @@ void notSerializable(Object obj) { } return info; }); - if (track.stackInfo != null && !track.stackInfo.isEmpty()) { + if (!track.stackInfo.isEmpty()) { details.add(String.format( "Start Track ID: %d, Stack depth: %d. Reference stack: ", track.id, track.depth)); - details.addAll( - track.stackInfo.lines().collect(Collectors.toList())); + details.addAll(track.stackInfo); details.add(String.format("End Track ID: %d", track.id)); details.add(""); } @@ -153,9 +152,10 @@ void deserializationFailed(Exception ex) { .filter(serializedLambda -> serializedLambda .getFunctionalInterfaceClass() .equals(targetType.replace('.', '/'))) - .map(serializedLambda -> "\t" + serializedLambda - + System.lineSeparator() - + tracked.get(serializedLambda).stackInfo) + .flatMap(serializedLambda -> Stream.concat( + Stream.of("\t" + serializedLambda), + tracked.get(serializedLambda).stackInfo + .stream())) .collect(Collectors.joining(System.lineSeparator())); if (!bestCandidates.isEmpty()) { @@ -229,10 +229,19 @@ Optional dumpDeserializationStack() { .flatMap(stackEntry -> tracked.values().stream().filter( t -> t.getHandle() == stackEntry.getHandle()) .findFirst()) - .map(track -> "DESERIALIZATION STACK. Process failed at depth " - + track.depth + System.lineSeparator() - + "\t- object (class \"" + track.className + "\")" - + System.lineSeparator() + track.stackInfo); + .map(track -> { + StringJoiner joiner = new StringJoiner( + System.lineSeparator()); + joiner.add( + "DESERIALIZATION STACK. Process failed at depth " + + track.depth); + joiner.add("\t- object (class \"" + track.className + + "\")"); + if (!track.stackInfo.isEmpty()) { + track.stackInfo.forEach(joiner::add); + } + return joiner.toString(); + }); } return Optional.empty(); } @@ -284,7 +293,7 @@ private static String tryDetectClassCastTarget(String message) { public void track(Object object, Track track) { if (track == null) { - track = new Track(-1, -1, "", null); + track = new Track(-1, -1, null, null); } tracked.put(object, track); } diff --git a/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/Track.java b/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/Track.java index 471ac98..b372972 100644 --- a/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/Track.java +++ b/kubernetes-kit-starter/src/main/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/Track.java @@ -10,6 +10,8 @@ package com.vaadin.kubernetes.starter.sessiontracker.serialization.debug; import java.io.Serializable; +import java.util.Collection; +import java.util.List; import java.util.function.ToIntFunction; /** @@ -27,7 +29,7 @@ public final class Track implements Serializable { /** * Path to the object in the object graph. */ - public final String stackInfo; + public final transient List stackInfo; /** * Identifier of the instance inside the references table. * @@ -49,10 +51,11 @@ public final class Track implements Serializable { */ transient Object object; - public Track(int id, int depth, String stackInfo, Object object) { + public Track(int id, int depth, Collection stackInfo, + Object object) { this.id = id; this.depth = depth; - this.stackInfo = stackInfo; + this.stackInfo = stackInfo != null ? List.copyOf(stackInfo) : List.of(); this.object = object; this.className = (object != null) ? object.getClass().getName() : "NULL"; @@ -61,7 +64,7 @@ public Track(int id, int depth, String stackInfo, Object object) { private Track(int depth, Class type) { this.id = -1; this.depth = depth; - this.stackInfo = null; + this.stackInfo = List.of(); this.object = null; this.className = type.getName(); } From aa2b788ba6a41c11767e514dd320a18f8b9fabd4 Mon Sep 17 00:00:00 2001 From: Marco Collovati Date: Thu, 18 Apr 2024 15:12:59 +0200 Subject: [PATCH 2/5] add test --- .../SerializationDeserializationTest.java | 24 +++++++++++++++++++ 1 file changed, 24 insertions(+) diff --git a/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/SerializationDeserializationTest.java b/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/SerializationDeserializationTest.java index cb8d07d..fc33885 100644 --- a/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/SerializationDeserializationTest.java +++ b/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/SerializationDeserializationTest.java @@ -8,11 +8,15 @@ import java.util.List; import java.util.regex.Pattern; +import com.vaadin.kubernetes.starter.sessiontracker.serialization.debug.DebugMode; +import com.vaadin.kubernetes.starter.sessiontracker.serialization.debug.Track; +import com.vaadin.kubernetes.starter.test.EnableOnJavaIOReflection; import org.assertj.core.api.Assertions; import org.assertj.core.api.InstanceOfAssertFactories; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; +import org.mockito.ArgumentMatchers; import org.mockito.Mockito; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.context.ApplicationContext; @@ -100,6 +104,26 @@ void serialization_defaultInjectableFilter_componentIgnored( Mockito.verifyNoMoreInteractions(mockHandler); } + @Test + @EnableOnJavaIOReflection + void serialization_transientInspection_trackObjectsIgnored( + @Autowired TestConfig.CtorInjectionTarget obj) throws Exception { + List target = new ArrayList<>(); + target.add(new HashMap<>()); + target.add(obj); + target.add(new MimeType()); + + TransientHandler mockHandler = Mockito.mock(TransientHandler.class, + Mockito.withSettings().extraInterfaces(DebugMode.class)); + + ByteArrayOutputStream os = new ByteArrayOutputStream(); + TransientInjectableObjectOutputStream.newInstance(os, mockHandler) + .writeWithTransients(target); + + Mockito.verify(mockHandler, Mockito.never()) + .inspect(ArgumentMatchers.argThat(o -> o instanceof Track)); + } + @Test void defaultInspectionFilter_rejectJavaClasses() { Pattern pattern = TransientInjectableObjectOutputStream.INSPECTION_REJECTION_PATTERN; From e6a1a09c45f2f65d96765e1c03373e9b6bfa5dab Mon Sep 17 00:00:00 2001 From: Marco Collovati Date: Sat, 20 Apr 2024 14:53:03 +0200 Subject: [PATCH 3/5] simulate slow serialization --- .../debug/SerializationDebugRequestHandlerTest.java | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java b/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java index 5c36d78..c8b70ac 100644 --- a/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java +++ b/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java @@ -301,7 +301,7 @@ void handleRequest_serializationTimeout_timeoutReported() { properties.setTimeout(1); handler = new SerializationDebugRequestHandler(properties); - httpSession.setAttribute("OBJ1", new DeepNested()); + httpSession.setAttribute("OBJ1", new SlowSerialization()); runDebugTool(); Result result = resultHolder.get(); @@ -345,6 +345,17 @@ private static class ChildNotSerializable implements Serializable { private NotSerializable data = new NotSerializable(); } + private static class SlowSerialization extends DeepNested { + private void writeObject(ObjectOutputStream out) throws IOException { + try { + Thread.sleep(100); + } catch (InterruptedException e) { + throw new RuntimeException(e); + } + out.defaultWriteObject(); + } + } + private static class DeepNested implements Serializable { private final ChildNotSerializable root = new ChildNotSerializable(); From 61bb4f97fbda6f882373b9aa258d43b5e86896e4 Mon Sep 17 00:00:00 2001 From: Marco Collovati Date: Sat, 20 Apr 2024 14:55:25 +0200 Subject: [PATCH 4/5] fixed test --- .../debug/SerializationDebugRequestHandlerTest.java | 2 ++ 1 file changed, 2 insertions(+) diff --git a/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java b/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java index c8b70ac..692358d 100644 --- a/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java +++ b/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java @@ -1,6 +1,8 @@ package com.vaadin.kubernetes.starter.sessiontracker.serialization.debug; +import java.io.IOException; import java.io.ObjectInputStream; +import java.io.ObjectOutputStream; import java.io.Serializable; import java.util.ArrayList; import java.util.List; From 9403b1fd104a86d23d049ef9a0028592edd3f180 Mon Sep 17 00:00:00 2001 From: Marco Collovati Date: Sat, 20 Apr 2024 16:55:05 +0200 Subject: [PATCH 5/5] make test more reliable --- .../debug/SerializationDebugRequestHandlerTest.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java b/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java index 692358d..d7eaaa3 100644 --- a/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java +++ b/kubernetes-kit-starter/src/test/java/com/vaadin/kubernetes/starter/sessiontracker/serialization/debug/SerializationDebugRequestHandlerTest.java @@ -300,7 +300,7 @@ void handleRequest_unserializableObjects_replacedAndRestored() { @Test void handleRequest_serializationTimeout_timeoutReported() { SerializationProperties properties = new SerializationProperties(); - properties.setTimeout(1); + properties.setTimeout(100); handler = new SerializationDebugRequestHandler(properties); httpSession.setAttribute("OBJ1", new SlowSerialization()); @@ -350,7 +350,7 @@ private static class ChildNotSerializable implements Serializable { private static class SlowSerialization extends DeepNested { private void writeObject(ObjectOutputStream out) throws IOException { try { - Thread.sleep(100); + Thread.sleep(2000); } catch (InterruptedException e) { throw new RuntimeException(e); }