Fix crash on pack after dispose (#662)

* added performance test with clocks

ignore tests with clocks

* use simple logger instead of printlns

* checked that we call `finishRecording` at the same picture that we called a `beginRecording`

* make `Logger` internal

* disable assertions in rendering performance test with content; otherwise it might be too flaky

* unignore `FPS is near display refresh rate (multiple windows with clocks)`

skiko/src/awtMain/kotlin/org/jetbrains/skiko/SkiaLayer.awt.kt

@@ -291,7 +291,7 @@ actual open class SkiaLayer internal constructor(
                 redrawer = renderFactory.createRedrawer(this, renderApi, analytics, properties)
                 redrawer?.syncSize()
             } catch (e: RenderException) {
-                println(e.message)
+                Logger.warn("Fallback to next API: ${e.message}")
                 thrown = true
             }
         } while (thrown && fallbackRenderApiQueue.isNotEmpty())
@@ -513,7 +513,8 @@ actual open class SkiaLayer internal constructor(
         val pictureHeight = (height * contentScale).toInt().coerceAtLeast(0)
 
         val bounds = Rect.makeWH(pictureWidth.toFloat(), pictureHeight.toFloat())
-        val canvas = pictureRecorder!!.beginRecording(bounds)
+        val pictureRecorder = pictureRecorder!!
+        val canvas = pictureRecorder.beginRecording(bounds)
 
         // clipping
         for (component in clipComponents) {
@@ -528,10 +529,11 @@ actual open class SkiaLayer internal constructor(
         }
 
         // we can dispose layer during onRender
-        if (!isDisposed) {
+        // or even dispose it and pack it again
+        if (!isDisposed && !pictureRecorder.isClosed) {
             synchronized(pictureLock) {
                 picture?.instance?.close()
-                val picture = pictureRecorder!!.finishRecordingAsPicture()
+                val picture = pictureRecorder.finishRecordingAsPicture()
                 this.picture = PictureHolder(picture, pictureWidth, pictureHeight)
             }
         }
@@ -546,7 +548,7 @@ actual open class SkiaLayer internal constructor(
             // ignore
         } catch (e: RenderException) {
             if (!isDisposed) {
-                println(e.message)
+                Logger.warn("Exception in draw scope: ${e.message}")
                 findNextWorkingRenderApi()
                 redrawer?.redrawImmediately()
             }

skiko/src/awtMain/kotlin/org/jetbrains/skiko/context/Direct3DContextHandler.kt

@@ -3,6 +3,7 @@ package org.jetbrains.skiko.context
 import org.jetbrains.skia.Surface
 import org.jetbrains.skia.SurfaceProps
 import org.jetbrains.skia.impl.getPtr
+import org.jetbrains.skiko.Logger
 import org.jetbrains.skiko.SkiaLayer
 import org.jetbrains.skiko.redrawer.Direct3DRedrawer
 import java.lang.ref.Reference
@@ -20,11 +21,11 @@ internal class Direct3DContextHandler(layer: SkiaLayer) : JvmContextHandler(laye
             if (context == null) {
                 context = directXRedrawer.makeContext()
                 if (System.getProperty("skiko.hardwareInfo.enabled") == "true") {
-                    println(rendererInfo())
+                    Logger.info("Renderer info:\n ${rendererInfo()}")
                 }
             }
         } catch (e: Exception) {
-            println("${e.message}\nFailed to create Skia Direct3D context!")
+            Logger.warn("${e.message}\n Failed to create Skia Direct3D context!")
             return false
         }
         return true

skiko/src/awtMain/kotlin/org/jetbrains/skiko/context/DirectSoftwareContextHandler.kt

 package org.jetbrains.skiko.context
 
 import org.jetbrains.skia.impl.getPtr
+import org.jetbrains.skiko.Logger
 import org.jetbrains.skiko.SkiaLayer
 import org.jetbrains.skiko.redrawer.AbstractDirectSoftwareRedrawer
 import java.lang.ref.Reference
@@ -25,7 +26,7 @@ internal class DirectSoftwareContextHandler(layer: SkiaLayer) : JvmContextHandle
     override fun initContext(): Boolean {
         if (!isInited) {
             if (System.getProperty("skiko.hardwareInfo.enabled") == "true") {
-                println(rendererInfo())
+                Logger.info("Renderer info:\n ${rendererInfo()}")
             }
             isInited = true
         }

skiko/src/awtMain/kotlin/org/jetbrains/skiko/context/MetalContextHandler.kt

 package org.jetbrains.skiko.context
 
 import org.jetbrains.skia.*
+import org.jetbrains.skiko.Logger
 import org.jetbrains.skiko.RenderException
 import org.jetbrains.skiko.SkiaLayer
 import org.jetbrains.skiko.redrawer.MetalRedrawer
@@ -14,11 +15,11 @@ internal class MetalContextHandler(layer: SkiaLayer) : JvmContextHandler(layer)
             if (context == null) {
                 context = metalRedrawer.makeContext()
                 if (System.getProperty("skiko.hardwareInfo.enabled") == "true") {
-                    println(rendererInfo())
+                    Logger.info("Renderer info:\n ${rendererInfo()}")
                 }
             }
         } catch (e: Exception) {
-            println("${e.message}\nFailed to create Skia Metal context!")
+            Logger.warn("${e.message}\nFailed to create Skia Metal context!")
             return false
         }
         return true

skiko/src/awtMain/kotlin/org/jetbrains/skiko/context/OpenGLContextHandler.kt

@@ -9,11 +9,11 @@ internal class OpenGLContextHandler(layer: SkiaLayer) : JvmContextHandler(layer)
             if (context == null) {
                 context = makeGLContext()
                 if (System.getProperty("skiko.hardwareInfo.enabled") == "true") {
-                    println(rendererInfo())
+                    Logger.info("Renderer info:\n ${rendererInfo()}")
                 }
             }
         } catch (e: Exception) {
-            println("Failed to create Skia OpenGL context!")
+            Logger.warn("${e.message}\nFailed to create Skia OpenGL context!")
             return false
         }
         return true

skiko/src/awtMain/kotlin/org/jetbrains/skiko/context/SoftwareContextHandler.kt

@@ -4,6 +4,7 @@ import org.jetbrains.skia.Bitmap
 import org.jetbrains.skia.Canvas
 import org.jetbrains.skia.ColorAlphaType
 import org.jetbrains.skia.ImageInfo
+import org.jetbrains.skiko.Logger
 import org.jetbrains.skia.SurfaceProps
 import org.jetbrains.skiko.SkiaLayer
 import org.jetbrains.skiko.hostOs
@@ -38,7 +39,7 @@ internal class SoftwareContextHandler(layer: SkiaLayer) : JvmContextHandler(laye
         // Raster does not need context
         if (!isInited) {
             if (System.getProperty("skiko.hardwareInfo.enabled") == "true") {
-                println(rendererInfo())
+                Logger.info("Renderer info:\n ${rendererInfo()}")
             }
             isInited = true
         }

skiko/src/awtTest/kotlin/org/jetbrains/skiko/SkiaLayerPerformanceTest.kt

 package org.jetbrains.skiko
 
 import kotlinx.coroutines.delay
-import org.jetbrains.skia.*
+import org.jetbrains.skia.Canvas
+import org.jetbrains.skia.Paint
+import org.jetbrains.skia.PaintMode
+import org.jetbrains.skia.Rect
 import org.jetbrains.skiko.util.UiTestScope
 import org.jetbrains.skiko.util.UiTestWindow
 import org.jetbrains.skiko.util.uiTest
@@ -9,10 +12,7 @@ import org.junit.Assume.assumeTrue
 import org.junit.Test
 import java.awt.Point
 import javax.swing.WindowConstants
-import kotlin.math.abs
-import kotlin.math.log2
-import kotlin.math.roundToInt
-import kotlin.math.sqrt
+import kotlin.math.*
 
 @Suppress("BlockingMethodInNonBlockingContext", "SameParameterValue")
 class SkiaLayerPerformanceTest {
@@ -20,10 +20,11 @@ class SkiaLayerPerformanceTest {
         val window: UiTestWindow
         val isCollected: Boolean
         fun startCollect()
-        fun printInfo()
+        fun printInfo(assert: Boolean)
     }
 
     private fun UiTestScope.performanceHelper(
+        scene: (canvas: Canvas, width: Int, height: Int, nanoTime: Long) -> Unit,
         width: Int,
         height: Int,
         frameCount: Int,
@@ -53,6 +54,7 @@ class SkiaLayerPerformanceTest {
             window.defaultCloseOperation = WindowConstants.DISPOSE_ON_CLOSE
             window.layer.skikoView = object : SkikoView {
                 override fun onRender(canvas: Canvas, width: Int, height: Int, nanoTime: Long) {
+                    scene(canvas, width, height, nanoTime)
                     if (canCollect && frameTimes.size < frameCount) {
                         frameTimes.add(System.nanoTime()) // we check the real time, not the time provided by the argument
                     }
@@ -67,7 +69,7 @@ class SkiaLayerPerformanceTest {
             canCollect = true
         }
 
-        override fun printInfo() {
+        override fun printInfo(assert: Boolean) {
             println("[Window frame times ($frameCount frames)]")
             val millis = frameTimeDeltas.map { it / 1E6 }
             println("Deltas " + millis.map { String.format("%.1f", it) })
@@ -86,11 +88,11 @@ class SkiaLayerPerformanceTest {
             ) {
                 val slowFrames = frameTimeDeltas.filter { it > 1E9 / 55 }
                 val fastFrames = frameTimeDeltas.filter { it < expectedFrameNanos * 0.5 }
-                if (slowFrames.size > deviatedTerminalCount) {
+                if (assert && slowFrames.size > deviatedTerminalCount) {
                     val str = slowFrames.map { String.format("%.1f", it / 1E6) }
                     throw AssertionError("Framerate is too low:\n$str")
                 }
-                if (fastFrames.size > deviatedTerminalCount) {
+                if (assert && fastFrames.size > deviatedTerminalCount) {
                     val str = fastFrames.map { String.format("%.1f", it / 1E6) }
                     throw AssertionError("Framerate is too high:\n$str")
                 }
@@ -104,7 +106,7 @@ class SkiaLayerPerformanceTest {
                 println(deviateMessage(expectedDeviatePercent2, deviated2 - deviated3 - deviatedTerminal))
                 println(deviateMessage(expectedDeviatePercent3, deviated3 - deviatedTerminal))
 
-                if (deviatedTerminal.size > deviatedTerminalCount) {
+                if (assert && deviatedTerminal.size > deviatedTerminalCount) {
                     throw AssertionError(deviateMessage(expectedDeviatePercentTerminal, deviatedTerminal))
                 } else {
                     println(deviateMessage(expectedDeviatePercentTerminal, deviatedTerminal))
@@ -127,12 +129,65 @@ class SkiaLayerPerformanceTest {
         }
     }
 
+    private val emptyScene = { canvas: Canvas, width: Int, height: Int, nanoTime: Long -> }
+
+    private val clocksScene = { canvas: Canvas, width: Int, height: Int, nanoTime: Long ->
+        val watchFill = Paint().apply { color = 0xFFFFFFFF.toInt() }
+        val watchStroke = Paint().apply {
+            color = 0xFF000000.toInt()
+            mode = PaintMode.STROKE
+            strokeWidth = 1f
+        }
+        val watchStrokeAA = Paint().apply {
+            color = 0xFF000000.toInt()
+            mode = PaintMode.STROKE
+            strokeWidth = 1f
+        }
+        for (x in 0 .. (width - 50) step 50) {
+            for (y in 20 .. (height - 50) step 50) {
+                val stroke = if (x > width / 2) watchStrokeAA else watchStroke
+                canvas.drawOval(Rect.makeXYWH(x + 5f, y + 5f, 40f, 40f), watchFill)
+                canvas.drawOval(Rect.makeXYWH(x + 5f, y + 5f, 40f, 40f), stroke)
+                var angle = 0f
+                while (angle < 2f * PI) {
+                    canvas.drawLine(
+                        (x + 25 - 17 * sin(angle)),
+                        (y + 25 + 17 * cos(angle)),
+                        (x + 25 - 20 * sin(angle)),
+                        (y + 25 + 20 * cos(angle)),
+                        stroke
+                    )
+                    angle += (2.0 * PI / 12.0).toFloat()
+                }
+                val time = (nanoTime / 1E6) % 60000 +
+                        (x.toFloat() / width * 5000).toLong() +
+                        (y.toFloat() / width * 5000).toLong()
+
+                val angle1 = (time.toFloat() / 5000 * 2f * PI).toFloat()
+                canvas.drawLine(x + 25f, y + 25f,
+                    x + 25f - 15f * sin(angle1),
+                    y + 25f + 15 * cos(angle1),
+                    stroke)
+
+                val angle2 = (time / 60000 * 2f * PI).toFloat()
+                canvas.drawLine(x + 25f, y + 25f,
+                    x + 25f - 10f * sin(angle2),
+                    y + 25f + 10f * cos(angle2),
+                    stroke)
+            }
+        }
+    }
+
     @Test
     fun `FPS is near display refresh rate (multiple windows)`() = uiTest {
         assumeTrue(System.getProperty("skiko.test.performance.enabled", "true") == "true")
 
         val helpers = (1..3).map { index ->
-            performanceHelper(width = 40, height = 20, frameCount = 300, deviatedTerminalCount = 20).apply {
+            performanceHelper(scene = emptyScene,
+                              width = 40,
+                              height = 20,
+                              frameCount = 300,
+                              deviatedTerminalCount = 20).apply {
                 window.toFront()
                 window.location = Point((index + 1) * 200, 200)
             }
@@ -141,7 +196,32 @@ class SkiaLayerPerformanceTest {
         try {
             helpers.forEach { it.startCollect() }
             awaitFrameCollection(helpers)
-            helpers.forEach { it.printInfo() }
+            helpers.forEach { it.printInfo(assert = true) }
+        } finally {
+            helpers.forEach { it.window.dispose() }
+        }
+    }
+
+    @Test
+    fun `FPS is near display refresh rate (multiple windows with clocks)`() = uiTest {
+        assumeTrue(System.getProperty("skiko.test.performance.enabled", "true") == "true")
+        val helpers = (1..3).map { index ->
+            performanceHelper(
+                scene = clocksScene,
+                width = 300,
+                height = 300,
+                frameCount = 300,
+                deviatedTerminalCount = 20
+            ).apply {
+                window.toFront()
+                window.location = Point(index * 300, 200)
+            }
+        }
+        delay(1000)
+        try {
+            helpers.forEach { it.startCollect() }
+            awaitFrameCollection(helpers)
+            helpers.forEach { it.printInfo(assert = false) }
         } finally {
             helpers.forEach { it.window.dispose() }
         }

skiko/src/commonMain/kotlin/org/jetbrains/skiko/Logging.kt

+package org.jetbrains.skiko
+
+internal object Logger {
+    fun info(msg: String) {
+        println("[SKIKO] info: $msg")
+    }
+
+    fun warn(msg: String) {
+        println("[SKIKO] warn: $msg")
+    }
+
+    fun error(msg: String) {
+        println("[SKIKO] error: $msg")
+    }
+}