Merged develop

rpgJavaInterpreter-core/src/main/kotlin/com/smeup/rpgparser/execution/Configuration.kt

@@ -287,7 +287,37 @@ data class JarikoCallback(
      * @return true if the feature flag is on, false otherwise - default implementation returns the feature flag default value
      * @see FeatureFlag.on
      * */
-    var featureFlagIsOn: ((featureFlag: FeatureFlag) -> Boolean) = { featureFlag -> featureFlag.on }
+    var featureFlagIsOn: ((featureFlag: FeatureFlag) -> Boolean) = { featureFlag -> featureFlag.on },
+
+    /**
+     * It is invoked whenever we start a telemetry trace.
+     * @param trace The object containing all the information about this trace.
+     */
+    var startJarikoTrace: ((trace: JarikoTrace) -> Unit) = {
+        // Defaults to a no-op
+    },
+
+    /**
+     * It is invoked whenever we finish a telemetry trace.
+     */
+    var finishJarikoTrace: (() -> Unit) = {
+        // Defaults to a no-op
+    },
+
+    /**
+     * It is invoked whenever we start a telemetry trace defined as annotation in an RPG program.
+     * @param trace The object containing all the information about this trace.
+     */
+    var startRpgTrace: ((trace: RpgTrace) -> Unit) = {
+        // Defaults to a no-op
+    },
+
+    /**
+     * It is invoked whenever we finish a telemetry trace defined as annotation in an RPG program.
+     */
+    var finishRpgTrace: (() -> Unit) = {
+        // Defaults to a no-op
+    }
 )
 
 /**

rpgJavaInterpreter-core/src/main/kotlin/com/smeup/rpgparser/execution/MainExecutionContext.kt

@@ -86,7 +86,12 @@ object MainExecutionContext {
                 )
             }
             return mainProgram.runCatching {
-                invoke(context.get())
+                val ctx = context.get()
+                val callback = ctx.configuration.jarikoCallback
+                val trace = JarikoTrace(JarikoTraceKind.MainExecutionContext)
+                callback.traceBlock(trace) {
+                    invoke(ctx)
+                }
             }.onFailure {
                 if (isRootContext) memorySliceMgr?.afterMainProgramInterpretation(false)
             }.onSuccess {

rpgJavaInterpreter-core/src/main/kotlin/com/smeup/rpgparser/interpreter/ExpressionEvaluation.kt

@@ -533,9 +533,12 @@ class ExpressionEvaluation(
 
     override fun eval(expression: FunctionCall): Value = proxyLogging(expression) {
         val functionToCall = expression.function.name
-        val function = systemInterface.findFunction(interpreterStatus.symbolTable, functionToCall)
-            ?: throw RuntimeException("Function $functionToCall cannot be found (${expression.position.line()})")
-        FunctionWrapper(function = function, functionName = functionToCall, expression).let { functionWrapper ->
+        val callback = MainExecutionContext.getConfiguration().jarikoCallback
+        val trace = JarikoTrace(JarikoTraceKind.FunctionCall, functionToCall)
+        callback.traceBlock(trace) {
+            val function = systemInterface.findFunction(interpreterStatus.symbolTable, functionToCall)
+                ?: throw RuntimeException("Function $functionToCall cannot be found (${expression.position.line()})")
+            val functionWrapper = FunctionWrapper(function = function, functionName = functionToCall, expression)
             val paramsValues = expression.args.map {
                 if (it is DataRefExpr) {
                     FunctionValue(variableName = it.variable.name, value = it.evalWith(this))

rpgJavaInterpreter-core/src/main/kotlin/com/smeup/rpgparser/interpreter/program.kt

@@ -5,18 +5,18 @@
  * you may not use this file except in compliance with the License.
  * You may obtain a copy of the License at
  *
- *      https://www.apache.org/licenses/LICENSE-2.0
+ *     https://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 com.smeup.rpgparser.interpreter
 
+import com.smeup.rpgparser.execution.Configuration
 import com.smeup.rpgparser.execution.MainExecutionContext
 import com.smeup.rpgparser.logging.ProgramUsageType
 import com.smeup.rpgparser.parsing.ast.*
@@ -39,9 +39,13 @@ class RpgProgram(val cu: CompilationUnit, val name: String = "<UNNAMED RPG PROGR
 
     private var systemInterface: SystemInterface? = null
 
+    private val configuration: Configuration by lazy {
+        MainExecutionContext.getConfiguration()
+    }
+
     private val interpreter: InternalInterpreter by lazy {
         val interpreterCore = InternalInterpreter(this.systemInterface!!)
-        MainExecutionContext.getConfiguration().jarikoCallback.onInterpreterCreation(interpreterCore)
+        configuration.jarikoCallback.onInterpreterCreation(interpreterCore)
         interpreterCore
     }
 
@@ -82,102 +86,122 @@ class RpgProgram(val cu: CompilationUnit, val name: String = "<UNNAMED RPG PROGR
     }
 
     override fun execute(systemInterface: SystemInterface, params: LinkedHashMap<String, Value>): List<Value> {
-        val expectedKeys = params().asSequence().map { it.name }.toSet()
+        val callback = configuration.jarikoCallback
+        val trace = JarikoTrace(JarikoTraceKind.RpgProgram, this.name)
+        return callback.traceBlock(trace) {
+            val expectedKeys = params().asSequence().map { it.name }.toSet()
 
-        // Original params passed from the caller
-        val callerParams = LinkedHashMap(params)
+            // Original params passed from the caller
+            val callerParams = LinkedHashMap(params)
 
-        if (expectedKeys.size <= params.size) {
-            require(params.keys.toSet() == params().asSequence().map { it.name }.toSet()) {
-                "Expected params: ${params().asSequence().map { it.name }.joinToString(", ")}"
-            }
-        } else {
-            require(params().asSequence().map { it.name }.toSet().all { it in expectedKeys }) {
-                "Expected params: ${params().asSequence().map { it.name }.joinToString(", ")}"
-            }
-
-            // Set not passed params to NullValue
-            params().forEach {
-                if (it.name !in params.keys) {
-                    params[it.name] = NullValue
+            if (expectedKeys.size <= params.size) {
+                require(params.keys.toSet() == params().asSequence().map { it.name }.toSet()) {
+                    "Expected params: ${params().asSequence().map { it.name }.joinToString(", ")}"
+                }
+            } else {
+                require(params().asSequence().map { it.name }.toSet().all { it in expectedKeys }) {
+                    "Expected params: ${params().asSequence().map { it.name }.joinToString(", ")}"
                 }
-            }
-        }
-        this.systemInterface = systemInterface
-        val logSource = { LogSourceData.fromProgram(name) }
-        logHandlers.renderLog(LazyLogEntry.produceStatement(logSource, "INTERPRETATION", "START"))
-        val changedInitialValues: List<Value>
-        val elapsed = measureNanoTime {
-            interpreter.setInterpretationContext(object : InterpretationContext {
-                private var iDataWrapUpChoice: DataWrapUpChoice? = null
-                override val currentProgramName: String
-                    get() = name
-                override fun shouldReinitialize() = false
-                override var dataWrapUpChoice: DataWrapUpChoice?
-                    get() = iDataWrapUpChoice
-                    set(value) {
-                        iDataWrapUpChoice = value
-                    }
-            })
 
-            for (pv in params) {
-                val expectedType = params().find { it.name == pv.key }!!.type
-                val coercedValue = coerce(pv.value, expectedType)
-                require(coercedValue.assignableTo(expectedType)) {
-                    "param ${pv.key} was expected to have type $expectedType. It has value: $coercedValue"
+                // Set not passed params to NullValue
+                params().forEach {
+                    if (it.name !in params.keys) {
+                        params[it.name] = NullValue
+                    }
                 }
             }
-            if (!initialized) {
-                initialized = true
-
-                /**
-                 * As the RPG program stack is managed outside of this method, it is up to the caller of this method
-                 * to ensure it is in the correct state, that is:
-                 * - `lastIndex` is this RpgProgram
-                 * - `lastIndex - 1` is the RpgProgram that calls this RpgProgram
-                 *
-                 * Note: If these two rules are not followed at this point, do not expect RpgPrograms to behave correctly.
-                 * that means something is wrong with `MainExecutionContext.getProgramStack()` push and pop logic.
-                 */
-                val programStack = MainExecutionContext.getProgramStack()
-                val caller = if (programStack.size > 1) {
-                    val parentProgramIndex = programStack.lastIndex - 1
-                    programStack[parentProgramIndex]
-                } else {
-                    null
+            this.systemInterface = systemInterface
+            val logSource = { LogSourceData.fromProgram(name) }
+            logHandlers.renderLog(LazyLogEntry.produceStatement(logSource, "INTERPRETATION", "START"))
+            val changedInitialValues: List<Value>
+            val elapsed = measureNanoTime {
+                interpreter.setInterpretationContext(object : InterpretationContext {
+                    private var iDataWrapUpChoice: DataWrapUpChoice? = null
+                    override val currentProgramName: String
+                        get() = name
+
+                    override fun shouldReinitialize() = false
+                    override var dataWrapUpChoice: DataWrapUpChoice?
+                        get() = iDataWrapUpChoice
+                        set(value) {
+                            iDataWrapUpChoice = value
+                        }
+                })
+
+                for (pv in params) {
+                    val expectedType = params().find { it.name == pv.key }!!.type
+                    val coercedValue = coerce(pv.value, expectedType)
+                    require(coercedValue.assignableTo(expectedType)) {
+                        "param ${pv.key} was expected to have type $expectedType. It has value: $coercedValue"
+                    }
                 }
+                if (!initialized) {
+                    initialized = true
+
+                    /**
+                     * As the RPG program stack is managed outside of this method, it is up to the caller of this method
+                     * to ensure it is in the correct state, that is:
+                     * - `lastIndex` is this RpgProgram
+                     * - `lastIndex - 1` is the RpgProgram that calls this RpgProgram
+                     *
+                     * Note: If these two rules are not followed at this point, do not expect RpgPrograms to behave correctly.
+                     * that means something is wrong with `MainExecutionContext.getProgramStack()` push and pop logic.
+                     */
+                    val programStack = MainExecutionContext.getProgramStack()
+                    val caller = if (programStack.size > 1) {
+                        val parentProgramIndex = programStack.lastIndex - 1
+                        programStack[parentProgramIndex]
+                    } else {
+                        null
+                    }
 
-                val activationGroupType = cu.activationGroupType()?.let {
-                    when {
-                        // When there is no caller use the default activation group
-                        it is CallerActivationGroup && caller == null ->
-                            NamedActivationGroup(MainExecutionContext.getConfiguration().defaultActivationGroupName)
-                        else -> it
+                    val activationGroupType = cu.activationGroupType()?.let {
+                        when {
+                            // When there is no caller use the default activation group
+                            it is CallerActivationGroup && caller == null ->
+                                NamedActivationGroup(configuration.defaultActivationGroupName)
+
+                            else -> it
+                        }
+                    } ?: when (caller) {
+                        // for main program, which does not have a caller, activation group is fixed by config
+                        null -> NamedActivationGroup(configuration.defaultActivationGroupName)
+                        else -> CallerActivationGroup
                     }
-                } ?: when (caller) {
-                    // for main program, which does not have a caller, activation group is fixed by config
-                    null -> NamedActivationGroup(MainExecutionContext.getConfiguration().defaultActivationGroupName)
-                    else -> CallerActivationGroup
-                }
 
-                activationGroup = ActivationGroup(activationGroupType, activationGroupType.assignedName(caller))
+                    activationGroup = ActivationGroup(activationGroupType, activationGroupType.assignedName(caller))
+                }
+                configuration.jarikoCallback.onEnterPgm(
+                    name,
+                    interpreter.getGlobalSymbolTable()
+                )
+                // set reinitialization to false because symboltable cleaning currently is handled directly
+                // in internal interpreter before exit
+                // todo i don't know whether parameter reinitialization has still sense
+                interpreter.execute(this.cu, params, false, callerParams)
+                configuration.jarikoCallback.onExitPgm(
+                    name,
+                    interpreter.getGlobalSymbolTable(),
+                    null
+                )
+                params.keys.forEach { params[it] = interpreter[it] }
+                changedInitialValues = params().map { interpreter[it.name] }
+                // here clear symbol table if needed
+                interpreter.doSomethingAfterExecution()
+            }.nanoseconds
+            if (MainExecutionContext.isLoggingEnabled) {
+                logHandlers.renderLog(LazyLogEntry.produceStatement(logSource, "INTERPRETATION", "END"))
+                logHandlers.renderLog(
+                    LazyLogEntry.producePerformanceAndUpdateAnalytics(
+                        logSource,
+                        ProgramUsageType.Interpretation,
+                        "INTERPRETATION",
+                        elapsed
+                    )
+                )
             }
-            MainExecutionContext.getConfiguration().jarikoCallback.onEnterPgm(name, interpreter.getGlobalSymbolTable())
-            // set reinitialization to false because symboltable cleaning currently is handled directly
-            // in internal interpreter before exit
-            // todo i don't know whether parameter reinitialization has still sense
-            interpreter.execute(this.cu, params, false, callerParams)
-            MainExecutionContext.getConfiguration().jarikoCallback.onExitPgm(name, interpreter.getGlobalSymbolTable(), null)
-            params.keys.forEach { params[it] = interpreter[it] }
-            changedInitialValues = params().map { interpreter[it.name] }
-            // here clear symbol table if needed
-            interpreter.doSomethingAfterExecution()
-        }.nanoseconds
-        if (MainExecutionContext.isLoggingEnabled) {
-            logHandlers.renderLog(LazyLogEntry.produceStatement(logSource, "INTERPRETATION", "END"))
-            logHandlers.renderLog(LazyLogEntry.producePerformanceAndUpdateAnalytics(logSource, ProgramUsageType.Interpretation, "INTERPRETATION", elapsed))
+            changedInitialValues
         }
-        return changedInitialValues
     }
 
     override fun equals(other: Any?) =

rpgJavaInterpreter-core/src/main/kotlin/com/smeup/rpgparser/interpreter/tracing.kt

@@ -0,0 +1,61 @@
+/*
+ * Copyright 2019 Sme.UP S.p.A.
+ *
+ * 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
+ *
+ * https://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
+ * imitations under the License.
+ *
+ */
+
+package com.smeup.rpgparser.interpreter
+
+import com.smeup.rpgparser.execution.JarikoCallback
+
+/**
+ * Kind of a trace
+ */
+enum class JarikoTraceKind {
+    Parsing,
+    SymbolTable,
+    CompositeStatement,
+    CallStmt,
+    ExecuteSubroutine,
+    FunctionCall,
+    MainExecutionContext,
+    RpgProgram
+}
+
+/**
+ * A trace emitted by Jariko for telemetry purposes
+ */
+data class JarikoTrace(
+    val kind: JarikoTraceKind,
+    val description: String = ""
+)
+
+/**
+ * A trace emitted by an RPG program for telemetry purposes
+ */
+data class RpgTrace(
+    val program: String,
+    val description: String? = null
+)
+
+internal fun <T> JarikoCallback.traceBlock(trace: JarikoTrace, block: () -> T): T {
+    startJarikoTrace(trace)
+    try {
+        return block()
+    } catch (e: Exception) {
+        throw e
+    } finally {
+        finishJarikoTrace()
+    }
+}