Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

add perf stats via jna for unix (linux/mac) #978

Merged
merged 19 commits into from
Mar 20, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -55,3 +55,6 @@ cabal.project.local~
# Python files
*.pyc
__pycache__

# Misc
*.pprof
11 changes: 10 additions & 1 deletion hre/build.sbt
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,17 @@ lazy val hre = (project in file(".")).settings(
libraryDependencies += "ch.qos.logback" % "logback-classic" % "1.2.3",
libraryDependencies += "org.fusesource.jansi" % "jansi" % "2.4.0",
libraryDependencies += "net.harawata" % "appdirs" % "1.2.1",
libraryDependencies += "net.java.dev.jna" % "jna" % "5.13.0",

// Disable documentation generation
Compile / doc / sources := Nil,
Compile / packageDoc / publishArtifact := false,
)

Compile / PB.targets := Seq(
scalapb.gen(flatPackage = true) -> (Compile / sourceManaged).value / "scalapb"
),

Compile / PB.protoSources ++= Seq(
(Compile / sourceManaged).value / "protobuf"
),
)
89 changes: 89 additions & 0 deletions hre/src/main/java/hre/perf/Profile.scala
Original file line number Diff line number Diff line change
@@ -0,0 +1,89 @@
package hre.perf

import com.google.perftools
import com.google.perftools.profiles.{Sample, ValueType}

import java.io.FileOutputStream
import java.util.zip.GZIPOutputStream
import scala.collection.mutable

case object Profile {
private var currentProfile: Option[Profile] = None

def install(profile: Boolean): Unit =
if(profile) currentProfile = Some(Profile())

def update(stack: Seq[String], ownUsage: ResourceUsage, doUpdateChildUsage: Boolean): Unit =
currentProfile.foreach(_.update(stack, ownUsage, doUpdateChildUsage))

def finish(): Unit =
currentProfile.foreach(_.finish())
}

case class Profile() {
val builder = new ProfileBuilder()

import builder.{loc, str}

private val epochStartNanos = System.currentTimeMillis() * 1_000_000L

private var lastChildUsage = ResourceUsage.getAggregateChildren.get

private val valueTypes = Seq(
ValueType(str("agg"), str("microseconds")),
ValueType(str("aggUser"), str("microseconds")),
ValueType(str("aggSys"), str("microseconds")),
ValueType(str("selfUser"), str("microseconds")),
ValueType(str("selfSys"), str("microseconds")),
ValueType(str("childUser"), str("microseconds")),
ValueType(str("childSys"), str("microseconds")),
ValueType(str("wall"), str("microseconds")),
)

private val samples = mutable.ArrayBuffer[Sample]()

def update(stack: Seq[String], ownUsage: ResourceUsage, doUpdateChildUsage: Boolean): Unit = synchronized {
val deltaChild = if (doUpdateChildUsage) {
val childUsage = ResourceUsage.getAggregateChildren.get
val deltaChild = childUsage - lastChildUsage
lastChildUsage = childUsage
deltaChild
} else {
ResourceUsage.zero
}

val deltaAgg = deltaChild + ownUsage

val locations = stack.map(loc)

samples += Sample(
locationId = locations,
value = Seq(
deltaAgg.userTime + deltaAgg.systemTime,
deltaAgg.userTime,
deltaAgg.systemTime,
ownUsage.userTime,
ownUsage.systemTime,
deltaChild.userTime,
deltaChild.systemTime,
ownUsage.wallTime,
),
)
}

def finish(): Unit = {
val result = perftools.profiles.Profile(
sampleType = valueTypes,
sample = samples.toIndexedSeq,
mapping = Nil,
location = builder.finishLocationTable(),
function = builder.finishFunctionTable(),
stringTable = builder.finishStringTable(),
timeNanos = epochStartNanos,
defaultSampleType = builder.str("agg"),
)
val out = new GZIPOutputStream(new FileOutputStream("profile.pprof.gz"))
result.writeTo(out)
out.close()
}
}
35 changes: 35 additions & 0 deletions hre/src/main/java/hre/perf/ProfileBuilder.scala
Original file line number Diff line number Diff line change
@@ -0,0 +1,35 @@
package hre.perf

import com.google.perftools.profiles._

import scala.collection.mutable

class ProfileBuilder {
private val stringIndex = mutable.Map[String, Long]("" -> 0)
private val stringTable = mutable.ArrayBuffer[String]("")

def str(s: String): Long =
stringIndex.getOrElseUpdate(s, {
stringTable += s
stringIndex.size
})

def finishStringTable(): Seq[String] = stringTable.toIndexedSeq

private val locationIndex = mutable.Map[String, Long]()
private val locationTable = mutable.ArrayBuffer[Location]()
private val functionTable = mutable.ArrayBuffer[Function]()

def loc(s: String): Long =
locationIndex.getOrElseUpdate(s, {
val id = functionTable.size + 1
functionTable += Function(id = id, name = str(s))
locationTable += Location(id = id, line = Seq(Line(functionId = id)))
id
})

def finishLocationTable(): Seq[Location] = locationTable.toIndexedSeq
def finishFunctionTable(): Seq[Function] = functionTable.toIndexedSeq


}
64 changes: 64 additions & 0 deletions hre/src/main/java/hre/perf/ResourceUsage.scala
Original file line number Diff line number Diff line change
@@ -0,0 +1,64 @@
package hre.perf

import hre.perf.ResourceUsage.Microseconds
import hre.unix.{LibC, RUsage}

object ResourceUsage {
type Microseconds = Long

private val boot = System.nanoTime() / 1000L

private def get(who: Int): Option[ResourceUsage] = {
val usage = new RUsage()
if(LibC.INSTANCE.getrusage(who, usage) != 0) return None

Some(ResourceUsage(usage.ru_utime.toUsec, usage.ru_stime.toUsec, usage.ru_inblock, usage.ru_oublock, usage.ru_nvcsw, usage.ru_nivcsw, System.nanoTime() / 1000L - boot))
}

def getProcess: Option[ResourceUsage] = get(0)
def getCallingThread: Option[ResourceUsage] = get(1)
def getAggregateChildren: Option[ResourceUsage] = get(-1)

def zero: ResourceUsage = ResourceUsage(0, 0, 0, 0, 0, 0, 0)
}

case class ResourceUsage(
userTime: Microseconds,
systemTime: Microseconds,
readBlocks: Long,
writtenBlocks: Long,
voluntaryContextSwitches: Long,
involuntaryContextSwitches: Long,
wallTime: Microseconds,
) {
override def toString: String =
s"user=${userTime}μs sys=${systemTime}μs in=${readBlocks}blocks out=${writtenBlocks}blocks voluntaryYield=${voluntaryContextSwitches} involuntaryYield=${involuntaryContextSwitches}"

def applyOp(op: (Long, Long) => Long)(other: ResourceUsage): ResourceUsage = {
val result = ResourceUsage(
userTime = op(userTime, other.userTime),
systemTime = op(systemTime, other.systemTime),
readBlocks = op(readBlocks, other.readBlocks),
writtenBlocks = op(writtenBlocks, other.writtenBlocks),
voluntaryContextSwitches = op(voluntaryContextSwitches, other.voluntaryContextSwitches),
involuntaryContextSwitches = op(involuntaryContextSwitches, other.involuntaryContextSwitches),
wallTime = op(wallTime, other.wallTime),
)
assert(result.userTime >= 0)
assert(result.systemTime >= 0)
assert(result.readBlocks >= 0)
assert(result.writtenBlocks >= 0)
assert(result.voluntaryContextSwitches >= 0)
assert(result.involuntaryContextSwitches >= 0)
// PB: wall time may travel in time:
// thread1.wallTime = 3s
// thread2.wallTime = 2s
// process.wallTime = 4s < 3s + 2s
// e.g. the "own" time of the process will then be negative in a flame graph to indicate this.
// assert(result.wallTime >= 0)
result
}

def -(other: ResourceUsage): ResourceUsage = applyOp(_ - _)(other)
def +(other: ResourceUsage): ResourceUsage = applyOp(_ + _)(other)
}
98 changes: 98 additions & 0 deletions hre/src/main/java/hre/progress/Layout.scala
Original file line number Diff line number Diff line change
@@ -0,0 +1,98 @@
package hre.progress

import org.fusesource.jansi.{AnsiConsole, AnsiType}

case object Layout {
var forceProgress: Boolean = false

val PROGRESS_BLOCKS = " ▏▎▍▌▋▊▉█"

def install(progress: Boolean): Unit = {
forceProgress = progress
AnsiConsole.systemInstall()
}

private def wantProgress: Boolean = AnsiConsole.out().getType match {
case AnsiType.Native | AnsiType.VirtualTerminal | AnsiType.Emulation => true
case AnsiType.Unsupported | AnsiType.Redirected => forceProgress
}

private def wantPrettyProgress: Boolean = AnsiConsole.out().getType match {
case AnsiType.Native | AnsiType.VirtualTerminal | AnsiType.Emulation => true
case AnsiType.Unsupported | AnsiType.Redirected => false
}

def maxWidth: Int = (AnsiConsole.out().getTerminalWidth match {
case 0 => 80
case other => other
}) - 2

def maxHeight: Int = 32

private def esc(command: Char, args: String = ""): String =
"\u001b[" + args + command

private def upBy(n: Int): String = if(n==0) "" else esc('A', n.toString)

private def clearLine: String = esc('K')
private def clearToEnd: String = esc('J', "0")

private var printedLines = 0

def undoProgressMessage: String =
if (wantProgress) {
if (wantPrettyProgress) {
val clearLines = printedLines
printedLines = 0
upBy(clearLines) + clearToEnd
} else {
"\r" + " ".repeat(maxWidth) + "\r"
}
} else ""

def progressEstimate: Double = TaskRegistry.getRootTask.progress

def progressBadge: String =
f"[${progressEstimate * 100}%.1f%%]"

def progressBar: String = {
val prefix = progressBadge + " ["
val postfix = "]"
val maxProgressBarWidth = maxWidth - prefix.length - postfix.length
val bumpedProgress = progressEstimate * 0.99 + 0.01
val progress = (bumpedProgress * maxProgressBarWidth * PROGRESS_BLOCKS.length).toInt
val fullBlocks = progress / PROGRESS_BLOCKS.length
val halfBlockIdx = progress % PROGRESS_BLOCKS.length

prefix + (
if (halfBlockIdx == 0) PROGRESS_BLOCKS.last.toString.repeat(fullBlocks) + " ".repeat(maxProgressBarWidth - fullBlocks)
else PROGRESS_BLOCKS.last.toString.repeat(fullBlocks) + PROGRESS_BLOCKS(halfBlockIdx) + " ".repeat(maxProgressBarWidth - fullBlocks - 1)
) + postfix
}

def progressMessage: String = if (TaskRegistry.getRootTask.nonEmpty) {
if (wantProgress) {
if (wantPrettyProgress) {
val lines = TaskRegistry.getRootTask.render(maxWidth, maxHeight-1)
printedLines = lines.size + 1
(progressBar +: lines).mkString("", f"%n", f"%n")
} else {
val lines = TaskRegistry.getRootTask.render(maxWidth, 1)
s"$progressBadge ${lines.last}"
}
} else ""
} else {
""
}

/**
* Print an updated progress message to stdout
* @return whether the number of printed progres lines changed
*/
def update(): Boolean = {
val lastPrintedLines = printedLines
System.out.print(undoProgressMessage)
System.out.print(progressMessage)
printedLines != lastPrintedLines
}
}
Loading