Add configurable logger, solidify workaround for JBR-5274 (#683)

* sometimes when we change scale via `EasyRes` or when we close/open lid and window is migrated to other screen `paint` is not called

see FL-18544

* customizable logger behaviour

* add debug logs in AWT layer

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

@@ -81,6 +81,7 @@ actual open class SkiaLayer internal constructor(
         layout = null
         backedLayer = object : HardwareLayer(externalAccessibleFactory) {
             override fun paint(g: java.awt.Graphics) {
+                Logger.debug { "Paint called on $this" }
                 checkContentScale()
 
                 // 1. JPanel.paint is not always called (in rare cases).
@@ -123,6 +124,7 @@ actual open class SkiaLayer internal constructor(
         }
 
         addPropertyChangeListener("graphicsContextScaleTransform") {
+            Logger.debug { "graphicsContextScaleTransform changed for $this" }
             redrawer?.syncSize()
             notifyChange(PropertyKind.ContentScale)
 
@@ -140,6 +142,7 @@ actual open class SkiaLayer internal constructor(
     private var fullscreenAdapter = FullscreenAdapter(backedLayer)
 
     override fun removeNotify() {
+        Logger.debug { "SkiaLayer.awt#removeNotify $this" }
         val window = SwingUtilities.getRoot(this) as Window
         window.removeComponentListener(fullscreenAdapter)
         dispose()
@@ -147,6 +150,7 @@ actual open class SkiaLayer internal constructor(
     }
 
     override fun addNotify() {
+        Logger.debug { "SkiaLayer.awt#addNotify $this" }
         super.addNotify()
         val window = SwingUtilities.getRoot(this) as Window
         window.addComponentListener(fullscreenAdapter)
@@ -314,7 +318,7 @@ actual open class SkiaLayer internal constructor(
                 redrawer = renderFactory.createRedrawer(this, renderApi, analytics, properties)
                 redrawer?.syncSize()
             } catch (e: RenderException) {
-                Logger.warn("Fallback to next API: ${e.message}")
+                Logger.warn(e) { "Fallback to next API" }
                 thrown = true
             }
         } while (thrown && fallbackRenderApiQueue.isNotEmpty())
@@ -365,6 +369,7 @@ actual open class SkiaLayer internal constructor(
     }
 
     override fun doLayout() {
+        Logger.debug { "doLayout on $this" }
         backedLayer.setBounds(0, 0, roundSize(width), roundSize(height))
         backedLayer.validate()
         redrawer?.syncSize()
@@ -372,6 +377,7 @@ actual open class SkiaLayer internal constructor(
 
 
     override fun paint(g: java.awt.Graphics) {
+        Logger.debug { "Paint called on: $this" }
         checkContentScale()
 
         // `paint` can be called when we already inside `draw` method.
@@ -524,6 +530,8 @@ actual open class SkiaLayer internal constructor(
         check(isEventDispatchThread()) { "Method should be called from AWT event dispatch thread" }
         check(!isDisposed) { "SkiaLayer is disposed" }
 
+        checkContentScale()
+
         FrameWatcher.nextFrame()
         fpsCounter?.tick()
 
@@ -566,7 +574,7 @@ actual open class SkiaLayer internal constructor(
             // ignore
         } catch (e: RenderException) {
             if (!isDisposed) {
-                Logger.warn("Exception in draw scope: ${e.message}")
+                Logger.warn(e) { "Exception in draw scope" }
                 findNextWorkingRenderApi()
                 redrawer?.redrawImmediately()
             }

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

@@ -21,11 +21,11 @@ internal class Direct3DContextHandler(layer: SkiaLayer) : JvmContextHandler(laye
             if (context == null) {
                 context = directXRedrawer.makeContext()
                 if (System.getProperty("skiko.hardwareInfo.enabled") == "true") {
-                    Logger.info("Renderer info:\n ${rendererInfo()}")
+                    Logger.info { "Renderer info:\n ${rendererInfo()}" }
                 }
             }
         } catch (e: Exception) {
-            Logger.warn("${e.message}\n Failed to create Skia Direct3D context!")
+            Logger.warn(e) { "Failed to create Skia Direct3D context!" }
             return false
         }
         return true

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

@@ -26,7 +26,7 @@ internal class DirectSoftwareContextHandler(layer: SkiaLayer) : JvmContextHandle
     override fun initContext(): Boolean {
         if (!isInited) {
             if (System.getProperty("skiko.hardwareInfo.enabled") == "true") {
-                Logger.info("Renderer info:\n ${rendererInfo()}")
+                Logger.info { "Renderer info:\n ${rendererInfo()}" }
             }
             isInited = true
         }

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

@@ -15,11 +15,11 @@ internal class MetalContextHandler(layer: SkiaLayer) : JvmContextHandler(layer)
             if (context == null) {
                 context = metalRedrawer.makeContext()
                 if (System.getProperty("skiko.hardwareInfo.enabled") == "true") {
-                    Logger.info("Renderer info:\n ${rendererInfo()}")
+                    Logger.info { "Renderer info:\n ${rendererInfo()}" }
                 }
             }
         } catch (e: Exception) {
-            Logger.warn("${e.message}\nFailed to create Skia Metal context!")
+            Logger.warn(e) { "Failed 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") {
-                    Logger.info("Renderer info:\n ${rendererInfo()}")
+                    Logger.info { "Renderer info:\n ${rendererInfo()}" }
                 }
             }
         } catch (e: Exception) {
-            Logger.warn("${e.message}\nFailed to create Skia OpenGL context!")
+            Logger.warn(e) { "Failed to create Skia OpenGL context!" }
             return false
         }
         return true

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

@@ -39,7 +39,7 @@ internal class SoftwareContextHandler(layer: SkiaLayer) : JvmContextHandler(laye
         // Raster does not need context
         if (!isInited) {
             if (System.getProperty("skiko.hardwareInfo.enabled") == "true") {
-                Logger.info("Renderer info:\n ${rendererInfo()}")
+                Logger.info { "Renderer info:\n ${rendererInfo()}" }
             }
             isInited = true
         }

skiko/src/awtMain/kotlin/org/jetbrains/skiko/redrawer/MetalRedrawer.kt

@@ -127,16 +127,16 @@ internal class MetalRedrawer(
         val rootPane = getRootPane(layer)
         val globalPosition = convertPoint(layer, layer.x, layer.y, rootPane)
         setContentScale(device, layer.contentScale)
-        resizeLayers(
-            device,
-            globalPosition.x,
-            rootPane.height - globalPosition.y - layer.height,
-            layer.width.coerceAtLeast(0),
-            layer.height.coerceAtLeast(0)
-        )
+        val x = globalPosition.x
+        val y = rootPane.height - globalPosition.y - layer.height
+        val width = layer.width.coerceAtLeast(0)
+        val height = layer.height.coerceAtLeast(0)
+        Logger.debug { "MetalRedrawer#resizeLayers $this $x $y $width $height" }
+        resizeLayers(device, x, y, width, height)
     }
 
     override fun setVisible(isVisible: Boolean) {
+        Logger.debug { "MetalRedrawer#setVisible $this $isVisible" }
         setLayerVisible(device, isVisible)
     }
 

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

 package org.jetbrains.skiko
 
+interface SkikoLoggerInterface {
+    val isTraceEnabled: Boolean
+    val isDebugEnabled: Boolean
+    val isInfoEnabled: Boolean
+    val isWarnEnabled: Boolean
+    val isErrorEnabled: Boolean
+
+    fun trace(message: String)
+    fun debug(message: String)
+    fun info(message: String)
+    fun warn(message: String)
+    fun error(message: String)
+
+    fun trace(t: Throwable, message: String)
+    fun debug(t: Throwable, message: String)
+    fun info(t: Throwable, message: String)
+    fun warn(t: Throwable, message: String)
+    fun error(t: Throwable, message: String)
+}
+
+fun setupSkikoLoggerFactory(createLogger: () -> SkikoLoggerInterface) {
+    Logger.loggerFactory = createLogger
+}
+
+internal object DefaultConsoleLogger: SkikoLoggerInterface {
+    override val isTraceEnabled: Boolean
+        get() = false
+    override val isDebugEnabled: Boolean
+        get() = false
+    override val isInfoEnabled: Boolean
+        get() = true
+    override val isWarnEnabled: Boolean
+        get() = true
+    override val isErrorEnabled: Boolean
+        get() = true
+
+    override fun trace(message: String) {
+        println("[SKIKO] trace: $message")
+    }
+
+    override fun trace(t: Throwable, message: String) {
+        println("[SKIKO] trace: $message")
+        println(t)
+    }
+
+    override fun debug(message: String) {
+        println("[SKIKO] debug: $message")
+    }
+
+    override fun debug(t: Throwable, message: String) {
+        println("[SKIKO] debug: $message")
+        println(t)
+    }
+
+    override fun info(message: String) {
+        println("[SKIKO] info: $message")
+    }
+
+    override fun info(t: Throwable, message: String) {
+        println("[SKIKO] info: $message")
+        println(t)
+    }
+
+    override fun warn(message: String) {
+        println("[SKIKO] warn: $message")
+    }
+
+    override fun warn(t: Throwable, message: String) {
+        println("[SKIKO] warn: $message")
+        println(t)
+    }
+
+    override fun error(message: String) {
+        println("[SKIKO] error: $message")
+    }
+
+    override fun error(t: Throwable, message: String) {
+        println("[SKIKO] error: $message")
+        println(t)
+    }
+}
+
 internal object Logger {
-    fun info(msg: String) {
-        println("[SKIKO] info: $msg")
+    var loggerFactory: () -> SkikoLoggerInterface = { DefaultConsoleLogger }
+
+    val loggerImpl by lazy {
+        loggerFactory()
+    }
+
+    inline fun trace(msg: () -> String) {
+        if (loggerImpl.isTraceEnabled) {
+            loggerImpl.trace(msg())
+        }
+    }
+
+    inline fun debug(msg: () -> String) {
+        if (loggerImpl.isDebugEnabled) {
+            loggerImpl.debug(msg())
+        }
     }
 
-    fun warn(msg: String) {
-        println("[SKIKO] warn: $msg")
+    inline fun info(msg: () -> String) {
+        if (loggerImpl.isInfoEnabled) {
+            loggerImpl.info(msg())
+        }
     }
 
-    fun error(msg: String) {
-        println("[SKIKO] error: $msg")
+    inline fun warn(msg: () -> String) {
+        if (loggerImpl.isWarnEnabled) {
+            loggerImpl.warn(msg())
+        }
+    }
+
+    inline fun error(msg: () -> String) {
+        if (loggerImpl.isErrorEnabled) {
+            loggerImpl.error(msg())
+        }
+    }
+
+    inline fun trace(t: Throwable, msg: () ->  String) {
+        if (loggerImpl.isTraceEnabled) {
+            loggerImpl.trace(t, msg())
+        }
+    }
+
+    inline fun debug(t: Throwable, msg: () ->  String) {
+        if (loggerImpl.isDebugEnabled) {
+            loggerImpl.debug(t, msg())
+        }
+    }
+
+    inline fun info(t: Throwable, msg: () -> String) {
+        if (loggerImpl.isInfoEnabled) {
+            loggerImpl.info(t, msg())
+        }
+    }
+    inline fun warn(t: Throwable, msg: () -> String) {
+        if (loggerImpl.isWarnEnabled) {
+            loggerImpl.warn(t, msg())
+        }
+    }
+    inline fun error(t: Throwable, msg:() ->  String) {
+        if (loggerImpl.isErrorEnabled) {
+            loggerImpl.error(t, msg())
+        }
     }
 }