More info

server/pipeline.js

@@ -153,10 +153,14 @@ let warmFlushEvery = 0
  * @param {Array<{ chart: string, context: string, ts: number, values: object }>} batch
  */
 function ingestBatch(store, anomalies, batch) {
+  const t0 = performance.now()
   store.ingest(batch)
+  const tIngest = performance.now()
   broadcastMetrics(batch)
+  const tBroadcast = performance.now()
 
   const fired = anomalies.evaluate(batch)
+  const tAnomaly = performance.now()
   for (const ev of fired) {
     broadcastAnomaly(ev)
     persistAlertEvent(ev)
@@ -181,6 +185,17 @@ function ingestBatch(store, anomalies, batch) {
     warmFlushEvery = 0
     flushWarmPending().catch(() => {})
   }
+  const dur = performance.now() - t0
+  if (dur > 10) {
+    log.debug('ingest', {
+      durMs: Math.round(dur * 10) / 10,
+      ingestMs: Math.round((tIngest - t0) * 10) / 10,
+      bcastMs: Math.round((tBroadcast - tIngest) * 10) / 10,
+      anomalyMs: Math.round((tAnomaly - tBroadcast) * 10) / 10,
+      charts: batch.length,
+      fired: fired.length,
+    })
+  }
 }
 
 export function startPipeline() {

server/services/collectors/cgroups.js

@@ -49,6 +49,20 @@ function readFile(p) {
   return readFileBuf(p)
 }
 
+let _profileIdx = 0
+function profile(label, fn) {
+  const t0 = performance.now()
+  const r = fn()
+  const dur = performance.now() - t0
+  if (dur > 2) {
+    _profileIdx++
+    if (_profileIdx <= 40) {
+      process.stderr.write(`cgroups:${label} ${Math.round(dur * 10) / 10}ms\n`)
+    }
+  }
+  return r
+}
+
 function cgroupRoot() {
   if (fs.existsSync('/sys/fs/cgroup/cgroup.controllers')) return '/sys/fs/cgroup'
   return null
@@ -280,18 +294,18 @@ export class CgroupsCollector extends EventEmitter {
       const memDetailDef = makeCgroupMemDetailChart(cg.id, title)
       const throttleDef = makeCgroupThrottleChart(cg.id, title)
 
-      const cpu = parseCpuStat(cg.path)
+      const cpu = profile('cpuStat:' + cg.id.slice(0,20), () => parseCpuStat(cg.path))
       let usageUsec = cpu?.usage_usec ?? 0
       let userUsec = cpu?.user_usec ?? 0
       let systemUsec = cpu?.system_usec ?? 0
       const throttledUsec = cpu?.throttled_usec ?? 0
 
-      const memCur = Number(readFile(path.join(cg.path, 'memory.current')) || 0)
+      const memCur = profile('memCur:' + cg.id.slice(0,20), () => Number(readFile(path.join(cg.path, 'memory.current')) || 0))
       const memMaxRaw = readFile(path.join(cg.path, 'memory.max'))
       const memMax =
         memMaxRaw && memMaxRaw.trim() !== 'max' ? Number(memMaxRaw.trim()) || 0 : 0
 
-      const io = parseIoStat(cg.path)
+      const io = profile('ioStat:' + cg.id.slice(0,20), () => parseIoStat(cg.path))
       const prev = this.prev.get(cg.id)
 
       let userPct = 0
@@ -333,7 +347,7 @@ export class CgroupsCollector extends EventEmitter {
         },
       })
 
-      const memStat = parseMemoryStat(cg.path)
+      const memStat = profile('memStat:' + cg.id.slice(0,20), () => parseMemoryStat(cg.path))
       if (memStat) {
         batch.push({
           chart: memDetailDef.id,

server/services/collectors/host-more.js

@@ -17,6 +17,20 @@ function readFile(p) {
   return readFileCached(p)
 }
 
+let _profileIdx = 0
+function profile(label, fn) {
+  const t0 = performance.now()
+  const r = fn()
+  const dur = performance.now() - t0
+  if (dur > 2) {
+    _profileIdx++
+    if (_profileIdx <= 20) {
+      process.stderr.write(`host_more:${label} ${Math.round(dur * 10) / 10}ms\n`)
+    }
+  }
+  return r
+}
+
 function rate(prev, cur, dtSec) {
   if (dtSec <= 0 || cur < prev) return 0
   return (cur - prev) / dtSec
@@ -487,7 +501,7 @@ export function collectKsmExtras(batch, ts) {
  */
 export function collectHostMore(batch, ts, dtSec, state, { mem, vm, prevVm } = {}) {
   // softirqs
-  const soft = parseSoftirqs()
+  const soft = profile('parseSoftirqs', parseSoftirqs)
   const prevSoft = state.lastSoftirqs
   if (Object.keys(soft).length) {
     /** @type {Record<string, number>} */
@@ -500,7 +514,7 @@ export function collectHostMore(batch, ts, dtSec, state, { mem, vm, prevVm } = {
   }
 
   // IRQs
-  const irqs = parseInterrupts()
+  const irqs = profile('parseInterrupts', parseInterrupts)
   const prevIrq = state.lastIrqs || {}
   /** @type {Record<string, number>} */
   const nextIrq = {}
@@ -520,7 +534,7 @@ export function collectHostMore(batch, ts, dtSec, state, { mem, vm, prevVm } = {
   state.lastIrqs = nextIrq
 
   // icmpmsg
-  const icmpMsg = parseIcmpMsg()
+  const icmpMsg = profile('parseIcmpMsg', parseIcmpMsg)
   const prevMsg = state.lastIcmpMsg
   if (Object.keys(icmpMsg).length) {
     const pick = (k) => (prevMsg ? rate(prevMsg[k] || 0, icmpMsg[k] || 0, dtSec) : 0)
@@ -543,7 +557,7 @@ export function collectHostMore(batch, ts, dtSec, state, { mem, vm, prevVm } = {
   }
 
   // ipv6
-  const s6 = parseSnmp6()
+  const s6 = profile('parseSnmp6', parseSnmp6)
   const prev6 = state.lastSnmp6
   if (Object.keys(s6).length) {
     const r = (k) => (prev6 ? rate(prev6[k] || 0, s6[k] || 0, dtSec) : 0)
@@ -585,7 +599,7 @@ export function collectHostMore(batch, ts, dtSec, state, { mem, vm, prevVm } = {
   }
 
   // conntrack
-  const ct = parseConntrack()
+  const ct = profile('parseConntrack', parseConntrack)
   const prevCt = state.lastCt
   batch.push({
     chart: 'net.conntrack',
@@ -619,15 +633,15 @@ export function collectHostMore(batch, ts, dtSec, state, { mem, vm, prevVm } = {
     chart: 'mem.pagetype_global',
     context: 'mem.pagetype_global',
     ts,
-    values: parsePagetypeGlobal(),
+    values: profile('parsePagetypeGlobal', parsePagetypeGlobal),
   })
 
-  collectNumaNodes(batch, ts)
-  collectCpuidle(batch, ts, dtSec, state)
-  collectPowercap(batch, ts, state)
-  collectEdac(batch, ts)
-  collectDebugfsExtras(batch, ts)
-  if (mem) collectMemExtras(batch, ts, mem)
-  collectThpMore(batch, ts, dtSec, vm, prevVm)
-  collectKsmExtras(batch, ts)
+  profile('collectNumaNodes', () => { collectNumaNodes(batch, ts); return true })
+  profile('collectCpuidle', () => { collectCpuidle(batch, ts, dtSec, state); return true })
+  profile('collectPowercap', () => { collectPowercap(batch, ts, state); return true })
+  profile('collectEdac', () => { collectEdac(batch, ts); return true })
+  profile('collectDebugfsExtras', () => { collectDebugfsExtras(batch, ts); return true })
+  if (mem) profile('collectMemExtras', () => { collectMemExtras(batch, ts, mem); return true })
+  profile('collectThpMore', () => { collectThpMore(batch, ts, dtSec, vm, prevVm); return true })
+  profile('collectKsmExtras', () => { collectKsmExtras(batch, ts); return true })
 }