fix(log): updated to stern from kubectl (#1437)

* fix(log): updated to stern from kubectl

* chore(stern): log test

* fix(stern): updated to use stern for tail

* improvement(logger): enable dynamic section widths

* improvement(test): added test to handle zero been falsey

* chore(test): added tests to k8s utilities

* style(stern): use more idiomatic boolean check

* style(stern): added more idomatic way of doing things

* style(stern): linter issues

* chore(stern): change test regex

Co-authored-by: Eyþór Magnússon <eysi09@gmail.com>

garden-service/src/commands/logs.ts

@@ -8,6 +8,7 @@
 
 import { Command, CommandResult, CommandParams, StringsParameter, IntegerParameter, BooleanParameter } from "./base"
 import chalk from "chalk"
+import { maxBy } from "lodash"
 import { ServiceLogEntry } from "../types/plugin/service/getServiceLogs"
 import Bluebird = require("bluebird")
 import { Service } from "../types/service"
@@ -65,6 +66,8 @@ export class LogsCommand extends Command<Args, Opts> {
     const { follow, tail } = opts
     const graph = await garden.getConfigGraph(log)
     const services = await graph.getServices(args.services)
+    const serviceNames = services.map((s) => s.name).filter(Boolean)
+    const maxServiceName = (maxBy(serviceNames, (serviceName) => serviceName.length) || "").length
 
     const result: ServiceLogEntry[] = []
     const stream = new Stream<ServiceLogEntry>()
@@ -82,7 +85,8 @@ export class LogsCommand extends Command<Args, Opts> {
 
       log.info({
         section: entry.serviceName,
-        msg: `${timestamp} → ${chalk.white(entry.msg)}`,
+        msg: `${chalk.yellowBright(timestamp)} → ${chalk.white(entry.msg)}`,
+        maxSectionWidth: maxServiceName,
       })
 
       if (!follow) {

garden-service/src/logger/log-entry.ts

@@ -41,6 +41,7 @@ interface MessageBase {
   symbol?: LogSymbol
   append?: boolean
   data?: any
+  maxSectionWidth?: number
 }
 
 export interface MessageState extends MessageBase {
@@ -106,6 +107,7 @@ export class LogEntry extends LogNode {
         symbol: params.symbol,
         status: params.level === LogLevel.error ? "error" : params.status,
         data: params.data,
+        maxSectionWidth: params.maxSectionWidth,
       })
     }
   }
@@ -131,6 +133,8 @@ export class LogEntry extends LogNode {
       // Next state does not inherit the append field
       append: updateParams.append,
       timestamp: Date.now(),
+      maxSectionWidth:
+        updateParams.maxSectionWidth !== undefined ? updateParams.maxSectionWidth : messageState.maxSectionWidth,
     }
 
     // Hack to preserve section alignment if spinner disappears

garden-service/src/logger/renderers.ts

@@ -26,13 +26,21 @@ type RenderFn = (entry: LogEntry) => string
 
 /*** STYLE HELPERS ***/
 
-const SECTION_PREFIX_WIDTH = 25
+export const MAX_SECTION_WIDTH = 25
 const cliPadEnd = (s: string, width: number): string => {
   const diff = width - stringWidth(s)
   return diff <= 0 ? s : s + repeat(" ", diff)
 }
-const truncateSection = (s: string) => cliTruncate(s, SECTION_PREFIX_WIDTH)
-const sectionStyle = (s: string) => chalk.cyan.italic(cliPadEnd(truncateSection(s), SECTION_PREFIX_WIDTH))
+
+function styleSection(section: string, width: number = MAX_SECTION_WIDTH) {
+  const minWidth = Math.min(width, MAX_SECTION_WIDTH)
+  const formattedSection = [section]
+    .map((s) => cliTruncate(s, minWidth))
+    .map((s) => cliPadEnd(s, minWidth))
+    .pop()
+  return chalk.cyan.italic(formattedSection)
+}
+
 export const msgStyle = (s: string) => (hasAnsi(s) ? s : chalk.gray(s))
 export const errorStyle = (s: string) => (hasAnsi(s) ? s : chalk.red(s))
 
@@ -153,11 +161,11 @@ export function renderData(entry: LogEntry): string {
 }
 
 export function renderSection(entry: LogEntry): string {
-  const { msg, section } = entry.getMessageState()
+  const { msg, section, maxSectionWidth } = entry.getMessageState()
   if (section && msg) {
-    return `${sectionStyle(section)} → `
+    return `${styleSection(section, maxSectionWidth)} → `
   } else if (section) {
-    return sectionStyle(section)
+    return styleSection(section, maxSectionWidth)
   }
   return ""
 }

garden-service/src/plugins/kubernetes/logs.ts

@@ -11,16 +11,18 @@ import { omit } from "lodash"
 import moment = require("moment")
 
 import { GetServiceLogsResult, ServiceLogEntry } from "../../types/plugin/service/getServiceLogs"
-import { splitFirst } from "../../util/util"
-import { kubectl } from "./kubectl"
 import { KubernetesResource, KubernetesPod } from "./types"
-import { getAllPods } from "./util"
+import { getAllPods, getStaticLabelsFromPod, getSelectorString } from "./util"
 import { KubeApi } from "./api"
 import { Service } from "../../types/service"
 import Stream from "ts-stream"
 import { LogEntry } from "../../logger/log-entry"
 import Bluebird from "bluebird"
 import { KubernetesProvider } from "./config"
+import { BinaryCmd } from "../../util/ext-tools"
+import { kubectl } from "./kubectl"
+import { splitFirst } from "../../util/util"
+import { ChildProcess } from "child_process"
 
 interface GetLogsBaseParams {
   defaultNamespace: string
@@ -44,6 +46,27 @@ interface GetLogsParams extends GetLogsBaseParams {
   pod: KubernetesPod
 }
 
+const STERN_NAME = "stern"
+const STERN_TIME_OUT = 300
+const stern = new BinaryCmd({
+  name: STERN_NAME,
+  defaultTimeout: STERN_TIME_OUT,
+  specs: {
+    darwin: {
+      url: "https://github.com/wercker/stern/releases/download/1.11.0/stern_darwin_amd64",
+      sha256: "7aea3b6691d47b3fb844dfc402905790665747c1e6c02c5cabdd41994533d7e9",
+    },
+    linux: {
+      url: "https://github.com/wercker/stern/releases/download/1.11.0/stern_linux_amd64",
+      sha256: "e0b39dc26f3a0c7596b2408e4fb8da533352b76aaffdc18c7ad28c833c9eb7db",
+    },
+    win32: {
+      url: "https://github.com/wercker/stern/releases/download/1.11.0/stern_windows_amd64.exe",
+      sha256: "75708b9acf6ef0eeffbe1f189402adc0405f1402e6b764f1f5152ca288e3109e",
+    },
+  },
+})
+
 /**
  * Stream all logs for the given pod names and service.
  */
@@ -56,11 +79,9 @@ export async function getPodLogs(params: GetPodLogsParams) {
       return resolve({})
     }
     for (const proc of procs) {
-      proc.on("error", reject)
+      proc.on("error", () => reject)
 
-      proc.on("exit", () => {
-        resolve({})
-      })
+      proc.on("exit", () => resolve({}))
     }
   })
 }
@@ -75,13 +96,23 @@ export async function getAllLogs(params: GetAllLogsParams) {
 }
 
 async function getLogs({ log, provider, service, stream, tail, follow, pod }: GetLogsParams) {
-  // TODO: do this via API instead of kubectl
-  const kubectlArgs = ["logs", "--tail", String(tail), "--timestamps=true", "--all-containers=true"]
-
   if (follow) {
-    kubectlArgs.push("--follow=true")
+    return followLogs(log, provider, service, stream, tail, pod)
   }
 
+  return readLogs(log, provider, service, stream, tail, pod)
+}
+
+async function readLogs(
+  log: LogEntry,
+  provider: KubernetesProvider,
+  service: Service,
+  stream: Stream<ServiceLogEntry>,
+  tail: number,
+  pod: KubernetesPod
+) {
+  const kubectlArgs = ["logs", "--tail", String(tail), "--timestamps=true", "--all-containers=true"]
+
   kubectlArgs.push(`pod/${pod.metadata.name}`)
 
   const proc = await kubectl.spawn({
@@ -90,22 +121,79 @@ async function getLogs({ log, provider, service, stream, tail, follow, pod }: Ge
     provider,
     namespace: pod.metadata.namespace,
   })
+
+  handleLogMessageStreamFromProcess(proc, stream, service)
+  return proc
+}
+async function followLogs(
+  log: LogEntry,
+  provider: KubernetesProvider,
+  service: Service,
+  stream: Stream<ServiceLogEntry>,
+  tail: number,
+  pod: KubernetesPod
+) {
+  const sternArgs = [
+    `--context=${provider.config.context}`,
+    `--namespace=${pod.metadata.namespace}`,
+    `--exclude-container=garden-*`,
+    "--tail",
+    String(tail),
+    "--output=json",
+    "-t",
+  ]
+
+  /* Getting labels on the pod with no numbers,
+  The Idea is these labels are less likely to change between different deployments of these pods
+  */
+  const labels = getStaticLabelsFromPod(pod)
+  if (Object.keys(labels).length > 0) {
+    sternArgs.push(`${getSelectorString(labels)}`)
+  } else {
+    sternArgs.push(`${service.name}`)
+  }
+
+  const proc = await stern.spawn({
+    args: sternArgs,
+    log,
+  })
+
+  handleLogMessageStreamFromProcess(proc, stream, service, true)
+  return proc
+}
+
+function handleLogMessageStreamFromProcess(
+  proc: ChildProcess,
+  stream: Stream<ServiceLogEntry>,
+  service: Service,
+  json?: boolean
+) {
   let timestamp: Date
 
   proc.stdout!.pipe(split()).on("data", (s) => {
     if (!s) {
       return
     }
-    const [timestampStr, msg] = splitFirst(s, " ")
+    const [timestampStr, msg] = json ? parseSternLogMessage(s) : splitFirst(s, " ")
     try {
       timestamp = moment(timestampStr).toDate()
     } catch {}
     void stream.write({
       serviceName: service.name,
       timestamp,
-      msg: `${pod.metadata.name} ${msg}`,
+      msg: `${msg}`,
     })
   })
+}
 
-  return proc
+function parseSternLogMessage(message: string): string[] {
+  let log = JSON.parse(message)
+  const logMessageChunks = log.message.split(" ")
+  return [
+    logMessageChunks[0],
+    logMessageChunks
+      .slice(1, logMessageChunks.length)
+      .join(" ")
+      .trimEnd(),
+  ]
 }

garden-service/src/plugins/kubernetes/util.ts

@@ -20,6 +20,7 @@ import { ConfigurationError } from "../../exceptions"
 import { KubernetesProvider } from "./config"
 import { LogEntry } from "../../logger/log-entry"
 
+const STATIC_LABEL_REGEX = /[0-9]/g
 export const workloadTypes = ["Deployment", "DaemonSet", "ReplicaSet", "StatefulSet"]
 
 export function getAnnotation(obj: KubernetesResource, key: string): string | null {
@@ -381,3 +382,22 @@ export async function getRunningPodInDeployment(deploymentName: string, provider
 
   return sample(pods)
 }
+
+export function getStaticLabelsFromPod(pod: KubernetesPod): { [key: string]: string } {
+  const labels: { [key: string]: string } = {}
+
+  for (const label in pod.metadata.labels) {
+    if (!pod.metadata.labels[label].match(STATIC_LABEL_REGEX)) {
+      labels[label] = pod.metadata.labels[label]
+    }
+  }
+  return labels
+}
+
+export function getSelectorString(labels: { [key: string]: string }) {
+  let selectorString: string = "-l"
+  for (const label in labels) {
+    selectorString += `${label}=${labels[label]},`
+  }
+  return selectorString.trimEnd().slice(0, -1)
+}

garden-service/test/e2e/src/pre-release.ts

@@ -173,15 +173,15 @@ describe("PreReleaseTests", () => {
             description: "get logs for node-service",
             condition: async () => {
               const logEntries = await runWithEnv(["logs", "node-service"])
-              return searchLog(logEntries, /node-service-v-.* App started/)
+              return searchLog(logEntries, /App started/)
             },
           },
           changeFileStep(resolve(hotReloadProjectPath, "node-service/app.js"), "change node-service/app.js"),
           {
             description: "get logs for node-service after hot reload event",
             condition: async () => {
               const logEntries = await runWithEnv(["logs", "node-service"])
-              return searchLog(logEntries, /node-service-v-.* App started/)
+              return searchLog(logEntries, /App started/)
             },
           },
         ]