fix(bulk-model-sync-lib): use carriage returns only on TTYs

The implemented progress reporting in the ModelImporter always used
carriage returns to report progress. This only works in terminals and
breaks incremental logging in setups like k8s.

This commit tries to detect if running in a terminal and if not, resorts
to logging calls for progress reporting. Logging output is reduced to
avoid excessive spam in captured log file.

Author: languitar

bulk-model-sync-lib/src/commonMain/kotlin/org/modelix/model/sync/bulk/ModelImporter.kt

@@ -77,12 +77,13 @@ class ModelImporter(private val root: INode, private val continueOnError: Boolea
             postponedReferences.clear()
             nodesToRemove.clear()
             numExpectedNodes = countExpectedNodes(data.root)
+            val progressReporter = ProgressReporter(numExpectedNodes.toULong(), logger)
             currentNodeProgress = 0
             buildExistingIndex(root)
 
             logger.info { "Importing nodes..." }
             data.root.originalId()?.let { originalIdToExisting[it] = root }
-            syncNode(root, data.root)
+            syncNode(root, data.root, progressReporter)
 
             logger.info { "Synchronizing references..." }
             postponedReferences.forEach {
@@ -107,18 +108,17 @@ class ModelImporter(private val root: INode, private val continueOnError: Boolea
     private fun countExpectedNodes(data: NodeData): Int =
         1 + data.children.sumOf { countExpectedNodes(it) }
 
-    private fun syncNode(node: INode, data: NodeData) {
+    private fun syncNode(node: INode, data: NodeData, progressReporter: ProgressReporter) {
         currentNodeProgress += 1
-        // print instead of log, so that the progress line can be overwritten by the carriage return
-        print("\r($currentNodeProgress / $numExpectedNodes) Synchronizing nodes...                    ")
+        progressReporter.step(currentNodeProgress.toULong())
         doAndPotentiallyContinueOnErrors {
             syncProperties(node, data)
-            syncChildren(node, data)
+            syncChildren(node, data, progressReporter)
             syncReferences(node, data)
         }
     }
 
-    private fun syncChildren(node: INode, data: NodeData) {
+    private fun syncChildren(node: INode, data: NodeData, progressReporter: ProgressReporter) {
         val allRoles = (data.children.map { it.role } + node.allChildren.map { it.roleInParent }).distinct()
         for (role in allRoles) {
             val expectedNodes = data.children.filter { it.role == role }
@@ -130,15 +130,15 @@ class ModelImporter(private val root: INode, private val continueOnError: Boolea
                     val expectedId = checkNotNull(expected.originalId()) { "Specified node '$expected' has no id" }
                     newChild.setPropertyValue(NodeData.idPropertyKey, expectedId)
                     originalIdToExisting[expectedId] = newChild
-                    syncNode(newChild, expected)
+                    syncNode(newChild, expected, progressReporter)
                 }
                 continue
             }
 
             // optimization for when there is no change in the child list
             // size check first to avoid querying the original ID
             if (expectedNodes.size == existingNodes.size && expectedNodes.map { it.originalId() } == existingNodes.map { it.originalId() }) {
-                existingNodes.zip(expectedNodes).forEach { syncNode(it.first, it.second) }
+                existingNodes.zip(expectedNodes).forEach { syncNode(it.first, it.second, progressReporter) }
                 continue
             }
 
@@ -163,7 +163,7 @@ class ModelImporter(private val root: INode, private val continueOnError: Boolea
                 }
                 check(childNode.getConceptReference() == expectedConcept) { "Unexpected concept change" }
 
-                syncNode(childNode, expected)
+                syncNode(childNode, expected, progressReporter)
             }
 
             nodesToRemove += node.getChildren(role).drop(expectedNodes.size)

bulk-model-sync-lib/src/commonMain/kotlin/org/modelix/model/sync/bulk/Util.kt

@@ -20,6 +20,7 @@ import mu.KLogger
 import org.modelix.model.api.BuiltinLanguages
 import org.modelix.model.data.ModelData
 import org.modelix.model.data.NodeData
+import kotlin.math.max
 
 /**
  * Checks if a module is included in the sync.
@@ -28,7 +29,11 @@ import org.modelix.model.data.NodeData
  * @param includedModules collection of included module names
  * @param includedPrefixes collection of included module name prefixes
  */
-fun isModuleIncluded(moduleName: String, includedModules: Collection<String>, includedPrefixes: Collection<String>): Boolean {
+fun isModuleIncluded(
+    moduleName: String,
+    includedModules: Collection<String>,
+    includedPrefixes: Collection<String>,
+): Boolean {
     val includedDirectly = includedModules.contains(moduleName)
     val includedByPrefix = includedPrefixes.any { prefix -> moduleName.startsWith(prefix) }
 
@@ -81,3 +86,33 @@ private fun measureImportSize(data: NodeData, metrics: ImportSizeMetrics = Impor
     data.children.forEach { measureImportSize(it, metrics) }
     return metrics
 }
+
+expect fun isTty(): Boolean
+
+class ProgressReporter(
+    private val total: ULong,
+    private val logger: KLogger,
+    private val print: (line: String) -> Unit = ::println,
+    private val isTty: () -> Boolean = ::isTty,
+) {
+
+    // Determine how often to log. For a small number of total nodes, ensure that we log at all. Otherwise,
+    // update progress ever 1% of the total to avoid spamming the output with log lines.
+    private val loggingStepSize = max(1UL, (total.toDouble() / 100).toULong())
+
+    /**
+     * Increments the progress. This function is assumed to be called for every element that's processed.
+     */
+    fun step(current: ULong) {
+        if (isTty()) {
+            // print instead of log, so that the progress line can be overwritten by the carriage return
+            print("\r($current / $total) Synchronizing nodes...                    ")
+        } else {
+            // Report on desired increments or first and last element to ensure users get important start and end
+            // information
+            if ((current % loggingStepSize) == 0UL || current == total || current == 1UL) {
+                logger.info { "($current / $total) Synchronizing nodes..." }
+            }
+        }
+    }
+}

bulk-model-sync-lib/src/jsMain/kotlin/org/modelix/model/sync/bulk/Utils.kt

@@ -0,0 +1,22 @@
+/*
+ * Copyright (c) 2023.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.modelix.model.sync.bulk
+
+actual fun isTty(): Boolean {
+    // Be safe and never assume a terminal as we cannot easily test for a TTY being attached
+    return false
+}

bulk-model-sync-lib/src/jvmMain/kotlin/org/modelix/model/sync/bulk/Utils.kt

@@ -0,0 +1,21 @@
+/*
+ * Copyright (c) 2023.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.modelix.model.sync.bulk
+
+actual fun isTty(): Boolean {
+    return System.console() != null
+}