added ability to count recursive rule/match calls.

v3.2.1-io
Nick Brown 2024-02-05 19:23:07 -05:00
parent 9b6beb068b
commit a57781b72f
Signed by: bicknrown
GPG Key ID: 47AF495B3DCCE9C3
1 changed files with 302 additions and 269 deletions

View File

@ -27,293 +27,326 @@ import org.apache.spark.sql.catalyst.plans.logical.LogicalPlan
object CustomLogger
{
val pushString: String = "push"
val popString: String = "pop"
val pushString: String = "push"
val popString: String = "pop"
val applyString: String = "Apply"
val transformString: String = "Transform"
val transformExpressionString: String = "TransformExpression"
val matchString: String = "Match"
val potentialMatchString: String = "Potential Match"
val effectiveMatchString: String = "Effective Match"
val ineffectiveMatchString: String = "Ineffective Match"
val executorString: String = "Executor"
val applyString: String = "Apply"
val transformString: String = "Transform"
val transformExpressionString: String = "TransformExpression"
val matchString: String = "Match"
val potentialMatchString: String = "Potential Match"
val effectiveMatchString: String = "Effective Match"
val ineffectiveMatchString: String = "Ineffective Match"
val executorString: String = "Executor"
val stateTimes: Map[String, Long] = Map[String, Long](
applyString -> 0,
transformString -> 0,
transformExpressionString -> 0,
matchString -> 0,
effectiveMatchString -> 0,
potentialMatchString -> 0,
ineffectiveMatchString -> 0,
executorString -> 0
)
val stateTimes: Map[String, Long] = Map[String, Long](
applyString -> 0,
transformString -> 0,
transformExpressionString -> 0,
matchString -> 0,
effectiveMatchString -> 0,
potentialMatchString -> 0,
ineffectiveMatchString -> 0,
executorString -> 0
)
val recurseFlags: Map[String, Boolean] = Map[String, Boolean](
applyString -> false,
transformString -> false,
transformExpressionString -> false,
matchString -> false,
effectiveMatchString -> false,
potentialMatchString -> false,
ineffectiveMatchString -> false,
executorString -> false
)
val recurseTimes: Map[String, Int] = Map[String, Int](
applyString -> 0,
transformString -> 0,
transformExpressionString -> 0,
matchString -> 0,
effectiveMatchString -> 0,
potentialMatchString -> 0,
ineffectiveMatchString -> 0,
executorString -> 0
)
var transformExpressionLogState: Boolean = false
var tempMatchBucket: Long = 0;
val intermediateStateStack: Stack[String] = Stack[String]()
var previousTimeStamp: Long = 0
var transformExpressionLogState: Boolean = false
var tempMatchBucket: Long = 0;
val intermediateStateStack: Stack[String] = Stack[String]()
var previousTimeStamp: Long = 0
val allRulesSet: Set[String] = Set[String]()
val effectiveRulesSet: Set[String] = Set[String]()
var currentRule: String = ""
val allRulesSet: Set[String] = Set[String]()
val effectiveRulesSet: Set[String] = Set[String]()
var currentRule: String = ""
def push(state: String): Unit =
def push(state: String): Unit =
{
val currentTime: Long = System.nanoTime
val timeDiff: Long = currentTime - previousTimeStamp
if (recurseFlags(state)) {
recurseTimes(state) += 1
}
recurseFlags(state) = true
if (intermediateStateStack.isEmpty)
{
val currentTime: Long = System.nanoTime
val timeDiff: Long = currentTime - previousTimeStamp
if (intermediateStateStack.isEmpty)
{
intermediateStateStack.push(state)
previousTimeStamp = currentTime
}
else if (intermediateStateStack.top == matchString)
{
stateTimes(intermediateStateStack.top) += timeDiff
tempMatchBucket += timeDiff
intermediateStateStack.push(state)
previousTimeStamp = currentTime
}
else
{
stateTimes(intermediateStateStack.top) += timeDiff
intermediateStateStack.push(state)
previousTimeStamp = currentTime
}
intermediateStateStack.push(state)
previousTimeStamp = currentTime
}
else if (intermediateStateStack.top == matchString)
{
stateTimes(intermediateStateStack.top) += timeDiff
tempMatchBucket += timeDiff
intermediateStateStack.push(state)
previousTimeStamp = currentTime
}
else
{
stateTimes(intermediateStateStack.top) += timeDiff
intermediateStateStack.push(state)
previousTimeStamp = currentTime
}
}
def pop(state: String, checkMatchFlag: Boolean = false): Unit =
{
val currentTime: Long = System.nanoTime
val timeDiff: Long = currentTime - previousTimeStamp
recurseFlags(state) = false
if (intermediateStateStack.isEmpty)
{
throw new RuntimeException(s"Empty stack! :'$state'")
}
else if (state == matchString)
{
stateTimes(intermediateStateStack.top) += timeDiff
tempMatchBucket += timeDiff
intermediateStateStack.pop
previousTimeStamp = currentTime
}
else if (checkMatchFlag && (intermediateStateStack.top == potentialMatchString))
{
if (state == effectiveMatchString)
{
stateTimes(effectiveMatchString) += tempMatchBucket
tempMatchBucket = 0
intermediateStateStack.pop
previousTimeStamp = currentTime
}
else if (state == ineffectiveMatchString)
{
stateTimes(ineffectiveMatchString) += tempMatchBucket
tempMatchBucket = 0
intermediateStateStack.pop
previousTimeStamp = currentTime
}
}
else if (intermediateStateStack.top != state)
{
val wrongState: String = intermediateStateStack.top
throw new RuntimeException(s"Cannot pop! :'$wrongState' != '$state'")
}
else
{
stateTimes(intermediateStateStack.top) += timeDiff
intermediateStateStack.pop
previousTimeStamp = currentTime
}
}
def checkMatch(
action: String = "",
ruleName: String = "",
effective: Boolean = false
): Unit =
{
if (action == pushString)
{
push(potentialMatchString)
}
else if (action == popString)
{
if (ruleName != "")
{
logRulesAsSets(ruleName, effective)
}
if (effective)
{
pop(effectiveMatchString, true)
}
else if (!effective)
{
pop(ineffectiveMatchString, true)
}
}
}
def logRulesAsSets(ruleName: String, effective: Boolean = false): Unit =
{
if (effective)
{
effectiveRulesSet += ruleName
}
def pop(state: String, checkMatchFlag: Boolean = false): Unit =
{
val currentTime: Long = System.nanoTime
val timeDiff: Long = currentTime - previousTimeStamp
if (intermediateStateStack.isEmpty)
{
throw new RuntimeException(s"Empty stack! :'$state'")
}
else if (state == matchString)
{
stateTimes(intermediateStateStack.top) += timeDiff
tempMatchBucket += timeDiff
intermediateStateStack.pop
previousTimeStamp = currentTime
}
else if (checkMatchFlag && (intermediateStateStack.top == potentialMatchString))
{
if (state == effectiveMatchString)
{
stateTimes(effectiveMatchString) += tempMatchBucket
tempMatchBucket = 0
intermediateStateStack.pop
previousTimeStamp = currentTime
}
else if (state == ineffectiveMatchString)
{
stateTimes(ineffectiveMatchString) += tempMatchBucket
tempMatchBucket = 0
intermediateStateStack.pop
previousTimeStamp = currentTime
}
}
else if (intermediateStateStack.top != state)
{
val wrongState: String = intermediateStateStack.top
throw new RuntimeException(s"Cannot pop! :'$wrongState' != '$state'")
}
else
{
stateTimes(intermediateStateStack.top) += timeDiff
intermediateStateStack.pop
previousTimeStamp = currentTime
}
}
allRulesSet += ruleName
}
def checkMatch(
action: String = "",
ruleName: String = "",
effective: Boolean = false
): Unit =
{
if (action == pushString)
{
push(potentialMatchString)
}
else if (action == popString)
{
if (ruleName != "")
{
logRulesAsSets(ruleName, effective)
}
if (effective)
{
pop(effectiveMatchString, true)
}
else if (!effective)
{
pop(ineffectiveMatchString, true)
}
}
}
def logRulesAsSets(ruleName: String, effective: Boolean = false): Unit =
{
if (effective)
{
effectiveRulesSet += ruleName
}
allRulesSet += ruleName
}
def logApplyTime[F](
descriptor: String = "",
context: String = "",
log: (String => Unit) =
// scalastyle:off println
println(_)
def logApplyTime[F](
descriptor: String = "",
context: String = "",
log: (String => Unit) =
// scalastyle:off println
println(_)
// scalastyle:on println
)(anonFunc: => F): F =
{
push(applyString)
val anonFuncRet = anonFunc
pop(applyString)
anonFuncRet
}
)(anonFunc: => F): F =
{
push(applyString)
val anonFuncRet = anonFunc
pop(applyString)
anonFuncRet
}
def logTransformTime[F](
descriptor: String = "",
context: String = "",
log: (String => Unit) =
// scalastyle:off println
println(_)
def logTransformTime[F](
descriptor: String = "",
context: String = "",
log: (String => Unit) =
// scalastyle:off println
println(_)
// scalastyle:on println
)(anonFunc: => F): F =
{
transformExpressionLogState = true
push(transformString)
val anonFuncRet = anonFunc
pop(transformString)
transformExpressionLogState = false
anonFuncRet
}
)(anonFunc: => F): F =
{
transformExpressionLogState = true
push(transformString)
val anonFuncRet = anonFunc
pop(transformString)
transformExpressionLogState = false
anonFuncRet
}
def logTransformExpressionTime[F](
descriptor: String = "",
context: String = "",
log: (String => Unit) =
// scalastyle:off println
println(_)
def logTransformExpressionTime[F](
descriptor: String = "",
context: String = "",
log: (String => Unit) =
// scalastyle:off println
println(_)
// scalastyle:on println
)(anonFunc: => F): F =
)(anonFunc: => F): F =
{
if (transformExpressionLogState)
{
if (transformExpressionLogState)
{
push(transformExpressionString)
val anonFuncRet = anonFunc
pop(transformExpressionString)
anonFuncRet
}
else
{
val anonFuncRet = anonFunc
anonFuncRet
}
push(transformExpressionString)
val anonFuncRet = anonFunc
pop(transformExpressionString)
anonFuncRet
}
else
{
val anonFuncRet = anonFunc
anonFuncRet
}
}
def logMatchTime[F](
descriptor: String = "",
unAffected: Boolean = false,
context: String = "",
log: (String => Unit) =
// scalastyle:off println
println(_)
def logMatchTime[F](
descriptor: String = "",
unAffected: Boolean = false,
context: String = "",
log: (String => Unit) =
// scalastyle:off println
println(_)
// scalastyle:on println
)(anonFunc: => F): F =
{
push(matchString)
val anonFuncRet = anonFunc
pop(matchString)
anonFuncRet
}
)(anonFunc: => F): F =
{
push(matchString)
val anonFuncRet = anonFunc
pop(matchString)
anonFuncRet
}
def logExecutionTime[F](
descriptor: String = "",
context: String = "",
log: (String => Unit) =
// scalastyle:off
println(_)
def logExecutionTime[F](
descriptor: String = "",
context: String = "",
log: (String => Unit) =
// scalastyle:off
println(_)
// scalastyle:on
)(anonFunc: => F): F =
{
push(executorString)
val anonFuncRet = anonFunc
pop(executorString)
anonFuncRet
}
)(anonFunc: => F): F =
{
push(executorString)
val anonFuncRet = anonFunc
pop(executorString)
anonFuncRet
}
def printData(
printJSON: Boolean = true,
printHumanReadable: Boolean = false,
printAllRules: Boolean = false,
printEffectiveRules: Boolean = false,
printASTSizes: Boolean = false,
optimizedASTSize: Long = 0,
analyzedASTSize: Long = 0
): Unit =
{
val applyTime: Long = stateTimes.getOrElse(applyString, -27)
val transformTime: Long = stateTimes.getOrElse(transformString, -27)
val transformExpressionTime: Long = stateTimes.getOrElse(transformExpressionString, -27)
val matchTime: Long = stateTimes.getOrElse(matchString, -27)
val effectiveMatchTime: Long = stateTimes.getOrElse(effectiveMatchString, -27)
val ineffectiveMatchTime: Long = stateTimes.getOrElse(ineffectiveMatchString, -27)
val executorTime: Long = stateTimes.getOrElse(executorString, -27)
def printData(
printJSON: Boolean = true,
printHumanReadable: Boolean = false,
printAllRules: Boolean = false,
printEffectiveRules: Boolean = false,
printASTSizes: Boolean = false,
optimizedASTSize: Long = 0,
analyzedASTSize: Long = 0
): Unit =
{
val applyTime: Long = stateTimes.getOrElse(applyString, -27)
val transformTime: Long = stateTimes.getOrElse(transformString, -27)
val transformExpressionTime: Long = stateTimes.getOrElse(transformExpressionString, -27)
val matchTime: Long = stateTimes.getOrElse(matchString, -27)
val effectiveMatchTime: Long = stateTimes.getOrElse(effectiveMatchString, -27)
val ineffectiveMatchTime: Long = stateTimes.getOrElse(ineffectiveMatchString, -27)
val executorTime: Long = stateTimes.getOrElse(executorString, -27)
if (printJSON)
{
// scalastyle:off
print(s"""
val applyTimeRecurse: Int = recurseTimes.getOrElse(applyString, -27)
val transformTimeRecurse: Int = recurseTimes.getOrElse(transformString, -27)
val transformExpressionTimeRecurse: Int = recurseTimes.getOrElse(transformExpressionString, -27)
val matchTimeRecurse: Int = recurseTimes.getOrElse(matchString, -27)
val effectiveMatchTimeRecurse: Int = recurseTimes.getOrElse(effectiveMatchString, -27)
val ineffectiveMatchTimeRecurse: Int = recurseTimes.getOrElse(ineffectiveMatchString, -27)
val executorTimeRecurse: Int = recurseTimes.getOrElse(executorString, -27)
if (printJSON)
{
// scalastyle:off
print(s"""
------------------------------
{"data":{"applyTime": $applyTime, "transformTime": $transformTime, "transformExpressionTime": $transformExpressionTime, "matchTime": $matchTime, "effectiveMatchTime": $effectiveMatchTime, "ineffectiveMatchTime": $ineffectiveMatchTime, "executorTime": $executorTime}}
------------------------------
""")
// scalastyle:on
}
// scalastyle:on
}
if (printHumanReadable)
{
val applyTimeSec: Double = (applyTime / 1000000000.0)
val transformTimeSec: Double = (transformTime / 1000000000.0)
val transformExpressionTimeSec: Double = (transformExpressionTime / 1000000000.0)
val effectiveMatchTimeSec: Double = (effectiveMatchTime / 1000000000.0)
val ineffectiveMatchTimeSec: Double = (ineffectiveMatchTime / 1000000000.0)
val matchTimeSec: Double = (matchTime / 1000000000.0)
val executorTimeSec: Double = (executorTime / 1000000000.0)
if (printHumanReadable)
{
val applyTimeSec: Double = (applyTime / 1000000000.0)
val transformTimeSec: Double = (transformTime / 1000000000.0)
val transformExpressionTimeSec: Double = (transformExpressionTime / 1000000000.0)
val effectiveMatchTimeSec: Double = (effectiveMatchTime / 1000000000.0)
val ineffectiveMatchTimeSec: Double = (ineffectiveMatchTime / 1000000000.0)
val matchTimeSec: Double = (matchTime / 1000000000.0)
val executorTimeSec: Double = (executorTime / 1000000000.0)
val matchTimeNotAccountedFor: Double = (applyTime - transformTime)
val matchTimeNotAccountedForSec: Double = (matchTimeNotAccountedFor / 1000000000.0)
val matchTimeNotAccountedFor: Double = (applyTime - transformTime)
val matchTimeNotAccountedForSec: Double = (matchTimeNotAccountedFor / 1000000000.0)
val totalTime: Double = (
transformTime + matchTime + executorTime + matchTimeNotAccountedFor)
val totalTimeSec: Double = (totalTime / 1000000000.0)
val totalTime: Double = (
transformTime + matchTime + executorTime + matchTimeNotAccountedFor)
val totalTimeSec: Double = (totalTime / 1000000000.0)
// scalastyle:off
print(s"""
// scalastyle:off
print(s"""
------------------------------
Total time for applying rules: $applyTime ns or $applyTimeSec seconds.
Total time for applying rules: $applyTime ns or $applyTimeSec seconds. Recursed $applyTimeRecurse times.
Total time for searching: $transformTime ns or $transformTimeSec seconds.
Total time for searching: $transformTime ns or $transformTimeSec seconds. Recursed $transformTimeRecurse times.
Total time for expression transformations: $transformExpressionTime ns or $transformExpressionTimeSec seconds.
Total time for expression transformations: $transformExpressionTime ns or $transformExpressionTimeSec seconds. Recursed $transformExpressionTimeRecurse times.
Time for effective rule matching: $effectiveMatchTime ns or $effectiveMatchTimeSec seconds.
Time for effective rule matching: $effectiveMatchTime ns or $effectiveMatchTimeSec seconds. Recursed $effectiveMatchTimeRecurse times.
Time for ineffective rule matching: $ineffectiveMatchTime ns or $ineffectiveMatchTimeSec seconds.
Time for ineffective rule matching: $ineffectiveMatchTime ns or $ineffectiveMatchTimeSec seconds. Recursed $ineffectiveMatchTimeRecurse times.
Total time for rule matching: $matchTime ns or $matchTimeSec seconds.
Total time for rule matching: $matchTime ns or $matchTimeSec seconds. Recursed $matchTimeRecurse times.
Time for rule matching and searching that is not being tracked: $matchTimeNotAccountedFor ns or $matchTimeNotAccountedForSec seconds.
@ -324,43 +357,43 @@ Total time for executor: $executorTime ns or $executorTimeSec seconds.
Total time for everything: $totalTime ns or $totalTimeSec seconds.
------------------------------
""")
// scalastyle:on
}
// scalastyle:on
}
if (printAllRules)
{
// scalastyle:off
print(s"""
if (printAllRules)
{
// scalastyle:off
print(s"""
------------------------------
Set of all rules:
$allRulesSet
------------------------------
""")
// scalastyle:on
}
// scalastyle:on
}
if (printEffectiveRules)
{
// scalastyle:off
print(s"""
if (printEffectiveRules)
{
// scalastyle:off
print(s"""
------------------------------
Set of effective rules:
$effectiveRulesSet
------------------------------
""")
// scalastyle:on
}
// scalastyle:on
}
if (printASTSizes)
{
// scalastyle:off
print(s"""
if (printASTSizes)
{
// scalastyle:off
print(s"""
------------------------------
Optimized AST Size: $optimizedASTSize
Analyzed AST Size: $analyzedASTSize
------------------------------
""")
// scalastyle:on
}
// scalastyle:on
}
}
}