Issue
Context
I’m working on a Kotlin program which runs on the JVM and consumes large amounts of memory. While I do trust the garbage collector to (eventually) free memory used by objects which are no longer reachable, I don’t trust future maintainers of the project (including my future self) – especially as the project progresses and becomes more evolved – to write the code in a way that makes sure that objects which are no longer needed are indeed unreachable.
So in order to reduce the risk, as part of my testing suite (which is already exhaustive with regards to the logic of the program’s functionality) I’m also writing (or trying to write, with different degrees of success) various tests which aim to ensure that references aren’t kept to objects which have run their course.
As this is quite difficult to do directly, the technique I’m using in the tests is to employ objects with finalizers, simulate the conditions when they’re no longer needed, force garbage collection, and assert the finalizers have indeed run. (Note: my question is not about this technique per se, but if someone has comments or ideas for improvement or can propose alternatives – I’ll be interested to hear!).
This generally works well, and can be shown to do the job, e.g. in TDD style: I write naive code which does the job as far as the business logic is concerned but doesn’t take care of losing references to old objects, I write a test as described above, I make sure that the test fails, I add code to take care of memory (e.g., in simple cases, set references to null), and then see that the test passes.
My question
For some reason, my tests don’t always work (clarification: I don’t mean that they fail non-deterministically; I mean that some of the tests consistently work and some consistently fail). The real examples from the project contain lots of intricate, proprietary details, but I’ve managed to boil it down to the following minimal example:
import kotlin.test.*
class FinalizationNotifier(val notify: () -> Unit) { protected fun finalize() = notify() }
class GcTest {
@Test fun `disposes of no-longer-used object`() {
var numTimesHasBeenDisposed = 0
// The following line allocates a (FinalizationNotifier) object, but keeps no reference to it
f(FinalizationNotifier { numTimesHasBeenDisposed++ }) // Note call to f, which in turn calls println
assertEquals(0, numTimesHasBeenDisposed) // Finalizer has not been run yet
System.gc() // Force garbage collection
Thread.sleep(1) // seems to be necessary to make sure finalizers have been run
assertEquals(1, numTimesHasBeenDisposed) // Finalizer has indeed been run
}
}
fun<T> f(value: T) { println(value) }
The test as written above passes, but if instead of calling f I call println directly – it fails (at the last assertion, i.e. the finalizer has not been run yet)! And my question is why that is, and/or what one should do in order to make sure (garbage gets collected and) finalizers are indeed run.
(Note: this is not about using println or calling my own functions; my real code is much more complex, and does call my own functions, and has nothing to do with printing. This is just a minimal example I’ve managed to come up with which shows the inconsistency.)
In case it matters, I’m using Kotlin 1.5.10 on Java 11.0.6 (on macOS).
Update:
I’ve written the two tests side-by-side (in file T.kt in package t); below please find the source code, as well as the disassembly (obtained using javap -c).
package t
import kotlin.test.*
class FinalizationNotifier(val notify: () -> Unit) { protected fun finalize() = notify() }
class GcTest {
@Test fun `disposes of no-longer-used object when calling own function`() {
var numTimesHasBeenDisposed = 0
f(FinalizationNotifier { numTimesHasBeenDisposed++ }) // Note call to f, which in turn calls println
assertEquals(0, numTimesHasBeenDisposed) // Finalizer has not been run yet
System.gc() // Force garbage collection
Thread.sleep(1) // seems to be necessary to make sure finalizers have been run
assertEquals(1, numTimesHasBeenDisposed) // Finalizer has indeed been run
}
@Test fun `disposes of no-longer-used object when calling println directly`() {
var numTimesHasBeenDisposed = 0
println(FinalizationNotifier { numTimesHasBeenDisposed++ }) // Note direct call to println
assertEquals(0, numTimesHasBeenDisposed) // Finalizer has not been run yet
System.gc() // Force garbage collection
Thread.sleep(1) // seems to be necessary to make sure finalizers have been run
assertEquals(1, numTimesHasBeenDisposed) // This fails for some reason
}
}
fun<T> f(value: T) { println(value) }
public final class t.FinalizationNotifier {
public t.FinalizationNotifier(kotlin.jvm.functions.Function0<kotlin.Unit>);
Code:
0: aload_1
1: ldc #10 // String notify
3: invokestatic #16 // Method kotlin/jvm/internal/Intrinsics.checkNotNullParameter:(Ljava/lang/Object;Ljava/lang/String;)V
6: aload_0
7: invokespecial #19 // Method java/lang/Object."<init>":()V
10: aload_0
11: aload_1
12: putfield #22 // Field notify:Lkotlin/jvm/functions/Function0;
15: return
public final kotlin.jvm.functions.Function0<kotlin.Unit> getNotify();
Code:
0: aload_0
1: getfield #22 // Field notify:Lkotlin/jvm/functions/Function0;
4: areturn
protected final void finalize();
Code:
0: aload_0
1: getfield #22 // Field notify:Lkotlin/jvm/functions/Function0;
4: invokeinterface #34, 1 // InterfaceMethod kotlin/jvm/functions/Function0.invoke:()Ljava/lang/Object;
9: pop
10: return
}
Compiled from "T.kt"
final class t.GcTest$disposes of no-longer-used object when calling own function$1 extends kotlin.jvm.internal.Lambda implements kotlin.jvm.functions.Function0<kotlin.Unit> {
final kotlin.jvm.internal.Ref$IntRef $numTimesHasBeenDisposed;
t.GcTest$disposes of no-longer-used object when calling own function$1(kotlin.jvm.internal.Ref$IntRef);
Code:
0: aload_0
1: aload_1
2: putfield #13 // Field $numTimesHasBeenDisposed:Lkotlin/jvm/internal/Ref$IntRef;
5: aload_0
6: iconst_0
7: invokespecial #16 // Method kotlin/jvm/internal/Lambda."<init>":(I)V
10: return
public final void invoke();
Code:
0: aload_0
1: getfield #13 // Field $numTimesHasBeenDisposed:Lkotlin/jvm/internal/Ref$IntRef;
4: getfield #26 // Field kotlin/jvm/internal/Ref$IntRef.element:I
7: istore_1
8: aload_0
9: getfield #13 // Field $numTimesHasBeenDisposed:Lkotlin/jvm/internal/Ref$IntRef;
12: iload_1
13: iconst_1
14: iadd
15: putfield #26 // Field kotlin/jvm/internal/Ref$IntRef.element:I
18: return
public java.lang.Object invoke();
Code:
0: aload_0
1: invokevirtual #29 // Method invoke:()V
4: getstatic #35 // Field kotlin/Unit.INSTANCE:Lkotlin/Unit;
7: areturn
}
Compiled from "T.kt"
final class t.GcTest$disposes of no-longer-used object when calling println directly$1 extends kotlin.jvm.internal.Lambda implements kotlin.jvm.functions.Function0<kotlin.Unit> {
final kotlin.jvm.internal.Ref$IntRef $numTimesHasBeenDisposed;
t.GcTest$disposes of no-longer-used object when calling println directly$1(kotlin.jvm.internal.Ref$IntRef);
Code:
0: aload_0
1: aload_1
2: putfield #13 // Field $numTimesHasBeenDisposed:Lkotlin/jvm/internal/Ref$IntRef;
5: aload_0
6: iconst_0
7: invokespecial #16 // Method kotlin/jvm/internal/Lambda."<init>":(I)V
10: return
public final void invoke();
Code:
0: aload_0
1: getfield #13 // Field $numTimesHasBeenDisposed:Lkotlin/jvm/internal/Ref$IntRef;
4: getfield #26 // Field kotlin/jvm/internal/Ref$IntRef.element:I
7: istore_1
8: aload_0
9: getfield #13 // Field $numTimesHasBeenDisposed:Lkotlin/jvm/internal/Ref$IntRef;
12: iload_1
13: iconst_1
14: iadd
15: putfield #26 // Field kotlin/jvm/internal/Ref$IntRef.element:I
18: return
public java.lang.Object invoke();
Code:
0: aload_0
1: invokevirtual #29 // Method invoke:()V
4: getstatic #35 // Field kotlin/Unit.INSTANCE:Lkotlin/Unit;
7: areturn
}
Compiled from "T.kt"
public final class t.GcTest {
public t.GcTest();
Code:
0: aload_0
1: invokespecial #8 // Method java/lang/Object."<init>":()V
4: return
public final void disposes of no-longer-used object when calling own function();
Code:
0: new #14 // class kotlin/jvm/internal/Ref$IntRef
3: dup
4: invokespecial #15 // Method kotlin/jvm/internal/Ref$IntRef."<init>":()V
7: astore_1
8: new #17 // class t/FinalizationNotifier
11: dup
12: new #19 // class "t/GcTest$disposes of no-longer-used object when calling own function$1"
15: dup
16: aload_1
17: invokespecial #22 // Method "t/GcTest$disposes of no-longer-used object when calling own function$1"."<init>":(Lkotlin/jvm/internal/Ref$IntRef;)V
20: checkcast #24 // class kotlin/jvm/functions/Function0
23: invokespecial #27 // Method t/FinalizationNotifier."<init>":(Lkotlin/jvm/functions/Function0;)V
26: invokestatic #33 // Method t/TKt.f:(Ljava/lang/Object;)V
29: iconst_0
30: invokestatic #39 // Method java/lang/Integer.valueOf:(I)Ljava/lang/Integer;
33: aload_1
34: getfield #43 // Field kotlin/jvm/internal/Ref$IntRef.element:I
37: invokestatic #39 // Method java/lang/Integer.valueOf:(I)Ljava/lang/Integer;
40: aconst_null
41: iconst_4
42: aconst_null
43: invokestatic #49 // Method kotlin/test/AssertionsKt.assertEquals$default:(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/String;ILjava/lang/Object;)V
46: invokestatic #54 // Method java/lang/System.gc:()V
49: lconst_1
50: invokestatic #60 // Method java/lang/Thread.sleep:(J)V
53: iconst_1
54: invokestatic #39 // Method java/lang/Integer.valueOf:(I)Ljava/lang/Integer;
57: aload_1
58: getfield #43 // Field kotlin/jvm/internal/Ref$IntRef.element:I
61: invokestatic #39 // Method java/lang/Integer.valueOf:(I)Ljava/lang/Integer;
64: aconst_null
65: iconst_4
66: aconst_null
67: invokestatic #49 // Method kotlin/test/AssertionsKt.assertEquals$default:(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/String;ILjava/lang/Object;)V
70: return
public final void disposes of no-longer-used object when calling println directly();
Code:
0: new #14 // class kotlin/jvm/internal/Ref$IntRef
3: dup
4: invokespecial #15 // Method kotlin/jvm/internal/Ref$IntRef."<init>":()V
7: astore_1
8: new #17 // class t/FinalizationNotifier
11: dup
12: new #65 // class "t/GcTest$disposes of no-longer-used object when calling println directly$1"
15: dup
16: aload_1
17: invokespecial #66 // Method "t/GcTest$disposes of no-longer-used object when calling println directly$1"."<init>":(Lkotlin/jvm/internal/Ref$IntRef;)V
20: checkcast #24 // class kotlin/jvm/functions/Function0
23: invokespecial #27 // Method t/FinalizationNotifier."<init>":(Lkotlin/jvm/functions/Function0;)V
26: astore_2
27: iconst_0
28: istore_3
29: getstatic #70 // Field java/lang/System.out:Ljava/io/PrintStream;
32: aload_2
33: invokevirtual #75 // Method java/io/PrintStream.println:(Ljava/lang/Object;)V
36: iconst_0
37: invokestatic #39 // Method java/lang/Integer.valueOf:(I)Ljava/lang/Integer;
40: aload_1
41: getfield #43 // Field kotlin/jvm/internal/Ref$IntRef.element:I
44: invokestatic #39 // Method java/lang/Integer.valueOf:(I)Ljava/lang/Integer;
47: aconst_null
48: iconst_4
49: aconst_null
50: invokestatic #49 // Method kotlin/test/AssertionsKt.assertEquals$default:(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/String;ILjava/lang/Object;)V
53: invokestatic #54 // Method java/lang/System.gc:()V
56: lconst_1
57: invokestatic #60 // Method java/lang/Thread.sleep:(J)V
60: iconst_1
61: invokestatic #39 // Method java/lang/Integer.valueOf:(I)Ljava/lang/Integer;
64: aload_1
65: getfield #43 // Field kotlin/jvm/internal/Ref$IntRef.element:I
68: invokestatic #39 // Method java/lang/Integer.valueOf:(I)Ljava/lang/Integer;
71: aconst_null
72: iconst_4
73: aconst_null
74: invokestatic #49 // Method kotlin/test/AssertionsKt.assertEquals$default:(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/String;ILjava/lang/Object;)V
77: return
}
Compiled from "T.kt"
public final class t.TKt {
public static final <T> void f(T);
Code:
0: iconst_0
1: istore_1
2: getstatic #13 // Field java/lang/System.out:Ljava/io/PrintStream;
5: aload_0
6: invokevirtual #18 // Method java/io/PrintStream.println:(Ljava/lang/Object;)V
9: return
}
Solution
It seems, Kotlin’s println(…) function has a different behavior than Java’s System.out.println(…) statement, regarding the order of evaluation.
In Java when you write
System.out.println(new Object() { {
System.setOut(new PrintStream(OutputStream.nullOutputStream()));
}});
The message will still be printed because the method receiver, System.out is evaluated, i.e. the field is read, first, before the argument expression is evaluated, i.e. the inner class object is created and its constructor executed. So the code will change System.out first, before printing using the value, System.out had before the change.
Therefore, the bytecode looks like
0: getstatic #35 // Field java/lang/System.out:Ljava/io/PrintStream;
3: new #41 // class my/test/EvaluationOrder$1
6: dup
7: invokespecial #43 // Method my/test/EvaluationOrder$1."<init>":()V
10: invokevirtual #44 // Method java/io/PrintStream.println:(Ljava/lang/Object;)V
The first instruction pushes the value of System.out to the operand stack, then the more involved object instantiation sequence follows, new creates and pushes a new uninitialized object, dup duplicates the reference, the following invokespecial consumes one and executes the constructor.
After that the stack contains the old value of System.out, followed by the reference to the initialized object, suitable to invoke the println method.
The bytecode generated by Kotlin is different:
8: new #17 // class t/FinalizationNotifier
11: dup
12: new #65 // class "t/GcTest$disposes of no-longer-used object when calling println directly$1"
15: dup
16: aload_1
17: invokespecial #66 // Method "t/GcTest$disposes of no-longer-used object when calling println directly$1"."<init>":(Lkotlin/jvm/internal/Ref$IntRef;)V
20: checkcast #24 // class kotlin/jvm/functions/Function0
23: invokespecial #27 // Method t/FinalizationNotifier."<init>":(Lkotlin/jvm/functions/Function0;)V
26: astore_2
27: iconst_0
28: istore_3
29: getstatic #70 // Field java/lang/System.out:Ljava/io/PrintStream;
32: aload_2
33: invokevirtual #75 // Method java/io/PrintStream.println:(Ljava/lang/Object;)V
Your use case is a bit more involved as the constructor invocation receives another freshly constructed object (instructions 12-20) but we can ignore this and focus on the other aspects.
The first cited instruction (number 8) is starting the creation of the object you’re going to print while the reading of System.out, as part of the print(…) function, is done afterwards, in instruction 29.
To bring these references in the order required for invokevirtual … println, i.e. [PrintStream, argument object], the generated code introduces a synthetic variable to hold the reference to the constructed object temporarily. Instruction 26, astore_2, stores the reference to the constructed object into variable #2. Then, as said, instruction 29 pushes the current value of System.out to the stack⁽¹⁾, and instruction 32, aload_2 loads the reference to the object from variable #2, which leads to the required stack contents to invoke println in instruction 33.
With one catch. Now, variable #2 contains a reference to the object and bytecode has no scopes nor variable deletion operations. The reference stays in the local variable until this variable is overwritten for a different purpose or the method returns. When we skim through the remaining code, we see that in this specific setup, variable #2 is not used again, therefore, when the code invokes System.gc(), the reference is still held in the synthetic variable and may prevent the garbage collection.
As explained in Can java finalize an object when it is still in scope? being referenced by a local variable is not preventing the garbage collection per se. Formally, the object is still eligible to garbage collection when it is not used beyond that point. But whether it gets garbage collected in practice, depends on the optimization state of the method. So it’s not surprising when this code reproducibly prevents garbage collection in your scenario.
If Kotlin supports using System.out.println(…) with the same behavior as Java instead of its built-in println(…) function, it should change the behavior.
⁽¹⁾ for whatever reason, instructions 27 and 28 store the constant zero in variable #3 which is never used. This doesn’t affect the behavior of the remaining code.
Answered By – Holger
Answer Checked By – David Marino (BugsFixing Volunteer)