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

Runme logging in output channel #521

Merged
merged 10 commits into from
May 19, 2023
3 changes: 3 additions & 0 deletions __mocks__/vscode.ts
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,9 @@ export const terminal = {
}

export const window = {
createOutputChannel: vi.fn().mockReturnValue({
appendLine: vi.fn()
}),
showWarningMessage: vi.fn(),
showInformationMessage: vi.fn(),
showErrorMessage: vi.fn(),
Expand Down
5 changes: 4 additions & 1 deletion src/extension/executors/runner.ts
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ import {
} from 'vscode'
import { Subject, debounceTime } from 'rxjs'

import getLogger from '../logger'
import { ClientMessages } from '../../constants'
import { ClientMessage } from '../../types'
import { PLATFORM_OS } from '../constants'
Expand All @@ -41,6 +42,7 @@ import { handleVercelDeployOutput, isVercelDeployScript } from './vercel'

import type { IEnvironmentManager } from '.'

const log = getLogger('executeRunner')
const LABEL_LIMIT = 15
const BACKGROUND_TASK_HIDE_TIMEOUT = 2000
const MIME_TYPES_WITH_CUSTOM_RENDERERS = ['text/plain']
Expand Down Expand Up @@ -285,7 +287,8 @@ export async function executeRunner(
// runs `program.close()` implicitly
execution.terminate()
} catch (err: any) {
throw new Error(`[Runme] Failed to terminate task: ${(err as Error).message}`)
log.error(`Failed to terminate task: ${(err as Error).message}`)
throw new Error(err)
}
})

Expand Down
4 changes: 3 additions & 1 deletion src/extension/executors/shell.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,10 +8,12 @@ import { NotebookCellOutputManager } from '../cell'
import { ENV_STORE } from '../constants'
import type { Kernel } from '../kernel'
import { getAnnotations } from '../utils'
import getLogger from '../logger'

import { handleVercelDeployOutput, isVercelDeployScript } from './vercel'

const MIME_TYPES_WITH_CUSTOM_RENDERERS = ['text/plain']
const log = getLogger('shellExecutor')

async function shellExecutor(
this: Kernel,
Expand All @@ -30,7 +32,7 @@ async function shellExecutor(
}
const outputItems: Buffer[] = []
const child = spawn(postScript, { cwd, shell: true, env })
console.log(`[Runme] Started process on pid ${child.pid}`)
log.info(`Started process on pid ${child.pid}`)
/**
* this needs more work / specification
*/
Expand Down
4 changes: 3 additions & 1 deletion src/extension/executors/task.ts
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import {
ShellExecution
} from 'vscode'

import getLogger from '../logger'
// import { ExperimentalTerminal } from "../terminal"
import { getCmdShellSeq, getAnnotations, getTerminalRunmeId } from '../utils'
import { PLATFORM_OS, ENV_STORE } from '../constants'
Expand All @@ -17,6 +18,7 @@ import { sh as inlineSh } from './shell'

const BACKGROUND_TASK_HIDE_TIMEOUT = 2000
const LABEL_LIMIT = 15
const log = getLogger('taskExecutor')

export function closeTerminalByEnvID (id: string, kill?: boolean) {
const terminal = window.terminals.find(t => getTerminalRunmeId(t) === id)
Expand Down Expand Up @@ -99,7 +101,7 @@ async function taskExecutor(
closeTerminalByEnvID(RUNME_ID)
resolve(0)
} catch (err: any) {
console.error(`[Runme] Failed to terminate task: ${(err as Error).message}`)
log.error(`Failed to terminate task: ${(err as Error).message}`)
resolve(1)
}
}))
Expand Down
4 changes: 3 additions & 1 deletion src/extension/executors/vercel/deploy.ts
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import { OutputType } from '../../../constants'
import type { Kernel } from '../../kernel'
import type { VercelState } from '../../../types'
import { NotebookCellOutputManager, updateCellMetadata } from '../../cell'
import getLogger from '../../logger'

import { listTeams, getUser, getProject, getProjects, createProject, cancelDeployment, VercelProject } from './api'
import { getAuthToken, quickPick, updateGitIgnore, createVercelFile } from './utils'
Expand All @@ -20,6 +21,7 @@ const LINK_OPTIONS = [
'Link Project to existing Vercel project',
'Create a new Vercel Project'
]
const log = getLogger('Vercel - deploy')

export async function deploy (
this: Kernel,
Expand Down Expand Up @@ -131,7 +133,7 @@ export async function deploy (
/**
* deploy application
*/
console.log(`[Runme] Deploy project "${deployParams.name}"`)
log.info(`Deploy project "${deployParams.name}"`)
let deploymentId: string | null = null
let deployCanceled = false
this.context.subscriptions.push(exec.token.onCancellationRequested(async () => {
Expand Down
7 changes: 5 additions & 2 deletions src/extension/handler/uri.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,12 +8,15 @@ import got from 'got'
import { v4 as uuidv4 } from 'uuid'
import { TelemetryReporter } from 'vscode-telemetry'

import getLogger from '../logger'

import {
getProjectDir, getTargetDirName, getSuggestedProjectName, writeBootstrapFile,
parseParams
} from './utils'

const REGEX_WEB_RESOURCE = /^https?:\/\//
const log = getLogger('RunmeUriHandler')

export class RunmeUriHandler implements UriHandler {
#context: ExtensionContext
Expand All @@ -22,7 +25,7 @@ export class RunmeUriHandler implements UriHandler {
}

async handleUri(uri: Uri) {
console.log(`[Runme] triggered RunmeUriHandler with ${uri}`)
log.info(`triggered RunmeUriHandler with ${uri}`)
const params = new URLSearchParams(uri.query)
const command = params.get('command')

Expand Down Expand Up @@ -152,7 +155,7 @@ export class RunmeUriHandler implements UriHandler {
.then(() => writeBootstrapFile(targetDirUri, fileToOpen))

progress.report({ increment: 50, message: 'Opening project...' })
console.log(`[Runme] Attempt to open folder ${targetDirUri.fsPath}`)
log.info(`Attempt to open folder ${targetDirUri.fsPath}`)
await commands.executeCommand('vscode.openFolder', targetDirUri, {
forceNewWindow: true
})
Expand Down
4 changes: 3 additions & 1 deletion src/extension/handler/utils.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,9 +2,11 @@ import url from 'node:url'

import { workspace, window, Uri, ExtensionContext } from 'vscode'

import getLogger from '../logger'
import { BOOTFILE } from '../constants'

const config = workspace.getConfiguration('runme.checkout')
const log = getLogger('RunmeUriHandler')

/**
* Get the project directory from the settings object.
Expand Down Expand Up @@ -86,7 +88,7 @@ export async function writeBootstrapFile(targetDirUri: Uri, fileToOpen: string)
Uri.joinPath(targetDirUri, BOOTFILE),
enc.encode(fileToOpen)
)
console.log(`[Runme] Created temporary bootstrap file to open ${fileToOpen}`)
log.info(`Created temporary bootstrap file to open ${fileToOpen}`)
}

/**
Expand Down
10 changes: 6 additions & 4 deletions src/extension/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,25 +2,27 @@ import type { ExtensionContext } from 'vscode'
import { TelemetryReporter } from 'vscode-telemetry'

import { RunmeExtension } from './extension'
import getLogger from './logger'

declare const INSTRUMENTATION_KEY: string

const ext = new RunmeExtension()
const log = getLogger()

export async function activate (context: ExtensionContext) {
TelemetryReporter.configure(context, INSTRUMENTATION_KEY)
console.log('[Runme] Activating Extension')
log.info('Activating Extension')
try {
await ext.initialize(context)
console.log('[Runme] Extension successfully activated')
log.info('Extension successfully activated')
} catch (err: any) {
console.log(`[Runme] Failed to initialize the extension: ${err.message}`)
log.error(`Failed to initialize the extension: ${err.message}`)
}

TelemetryReporter.sendTelemetryEvent('activate')
}

export function deactivate () {
console.log('[Runme] Deactivating Extension')
log.info('Deactivating Extension')
TelemetryReporter.sendTelemetryEvent('deactivate')
}
11 changes: 7 additions & 4 deletions src/extension/kernel.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ import { ClientMessages } from '../constants'
import { API } from '../utils/deno/api'
import { postClientMessage } from '../utils/messaging'

import getLogger from './logger'
import executor, { type IEnvironmentManager, ENV_STORE_MANAGER } from './executors'
import { DENO_ACCESS_TOKEN_KEY } from './constants'
import { resetEnv, getKey, getAnnotations, hashDocumentUri, processEnviron, isWindows } from './utils'
Expand All @@ -36,6 +37,8 @@ enum ConfirmationItems {
Cancel = 'Cancel'
}

const log = getLogger('Kernel')

export class Kernel implements Disposable {
static readonly type = 'runme' as const

Expand Down Expand Up @@ -146,7 +149,7 @@ export class Kernel implements Disposable {
}

if (cell.metadata?.['runme.dev/uuid'] === undefined) {
console.error(`[Runme] Cell with index ${cell.index} lacks uuid`)
log.error(`Cell with index ${cell.index} lacks uuid`)
continue
}

Expand Down Expand Up @@ -215,7 +218,7 @@ export class Kernel implements Disposable {
return
}

console.error(`[Runme] Unknown kernel event type: ${message.type}`)
log.error(`Unknown kernel event type: ${message.type}`)
}

private async _executeAll(cells: NotebookCell[]) {
Expand Down Expand Up @@ -323,7 +326,7 @@ export class Kernel implements Disposable {
)
.catch((e) => {
window.showErrorMessage(`Internal failure executing runner: ${e.message}`)
console.error('[Runme] Internal failure executing runner', e.message)
log.error('Internal failure executing runner', e.message)
return false
})

Expand Down Expand Up @@ -364,7 +367,7 @@ export class Kernel implements Disposable {
this.environment = env
} catch (e: any) {
window.showErrorMessage(`Failed to create environment for gRPC Runner: ${e.message}`)
console.error('[Runme] Failed to create gRPC Runner environment', e)
log.error('Failed to create gRPC Runner environment', e)
}
})
}
Expand Down
47 changes: 47 additions & 0 deletions src/extension/logger.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,47 @@
import util from 'node:util'

import { window } from 'vscode'

const outputChannel = window.createOutputChannel('Runme')

const COLOR_REGEXP = /[\u001b\u009b][[()#;?]*(?:[0-9]{1,4}(?:;[0-9]{0,4})*)?[0-9A-ORZcf-nqry=><]/g
christian-bromann marked this conversation as resolved.
Show resolved Hide resolved
const DEFAULT_LOG_LEVEL: LogLevel = 'info'

/**
* VS Code currently doesn't support colors, see
* https://github.com/microsoft/vscode/issues/571
* Therefor keep this minimal.
*/
const colors = {
reset: '\x1b[0m',
red: '\x1b[31m',
green: '\x1b[32m',
yellow: '\x1b[33m'
} as const
type LogLevel = 'trace' | 'info' | 'warn' | 'error'

function color (color: keyof typeof colors, text: string) {
return `${colors[color]}${text}${colors.reset}`
}

function log (scope?: string, logLevel: LogLevel = DEFAULT_LOG_LEVEL, ...logParams: string[]) {
const now = new Date()
const scopeAddition = scope ? color('yellow', `(${scope})`) : ''
const prefix = util.format(
`${color('green' ,'[%s]')} ${color('yellow', '%s')} Runme%s:`,
now.toISOString(),
logLevel ?? '',
scopeAddition
)
console.log(prefix, ...logParams)
outputChannel.appendLine([prefix, ...logParams].join(' ').replace(COLOR_REGEXP, ''))
}

export default function getLogger (scope?: string) {
return {
christian-bromann marked this conversation as resolved.
Show resolved Hide resolved
trace: (...logParams: string[]) => log(scope, 'trace', ...logParams),
info: (...logParams: string[]) => log(scope, 'info', ...logParams),
warn: (...logParams: string[]) => log(scope, 'warn', ...logParams),
error: (...logParams: string[]) => log(scope, 'error', ...logParams)
}
}
6 changes: 4 additions & 2 deletions src/extension/provider/runmeTask.ts
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ import {
NotebookCellData,
} from 'vscode'

import getLogger from '../logger'
import { getAnnotations, getWorkspaceEnvs, prepareCmdSeq } from '../utils'
import { Serializer, RunmeTaskDefinition } from '../../types'
import { SerializerBase } from '../serializer'
Expand All @@ -26,6 +27,7 @@ import { getShellPath, parseCommandSeq } from '../executors/utils'
import { Kernel } from '../kernel'

type TaskOptions = Pick<RunmeTaskDefinition, 'closeTerminalOnSuccess' | 'isBackground' | 'cwd'>
const log = getLogger('RunmeTaskProvider')

export interface RunmeTask extends Task {
definition: Required<RunmeTaskDefinition>
Expand All @@ -43,7 +45,7 @@ export class RunmeTaskProvider implements TaskProvider {

public async provideTasks(token: CancellationToken): Promise<Task[]> {
if(!this.runner) {
console.error('Tasks only supported with gRPC runner enabled')
log.error('Tasks only supported with gRPC runner enabled')
return []
}

Expand All @@ -61,7 +63,7 @@ export class RunmeTaskProvider implements TaskProvider {
mdContent = (await workspace.fs.readFile(current))
} catch (err: any) {
if (err.code !== 'FileNotFound') {
console.log(err)
log.error(`${err.message}`)
}
return []
}
Expand Down
9 changes: 6 additions & 3 deletions src/extension/server/runmeServer.ts
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import { ChannelCredentials } from '@grpc/grpc-js'
import { GrpcTransport } from '@protobuf-ts/grpc-transport'
import { Disposable, Uri, EventEmitter } from 'vscode'

import getLogger from '../logger'
import {
HealthCheckRequest,
HealthCheckResponse_ServingStatus
Expand Down Expand Up @@ -34,6 +35,8 @@ export interface IServerConfig {
}
}

const log = getLogger('RunmeServer')

class RunmeServer implements Disposable {
#port: number
#process: ChildProcessWithoutNullStreams | undefined
Expand Down Expand Up @@ -195,7 +198,7 @@ class RunmeServer implements Disposable {

process.on('close', (code) => {
if (this.#loggingEnabled) {
console.log(`[Runme] Server process #${this.#process?.pid} closed with code ${code}`)
log.info(`Server process #${this.#process?.pid} closed with code ${code}`)
}
this.#onClose.fire({ code })

Expand All @@ -204,12 +207,12 @@ class RunmeServer implements Disposable {


process.stderr.once('data', () => {
console.log(`[Runme] Server process #${this.#process?.pid} started on port ${this.#port}`)
log.info(`Server process #${this.#process?.pid} started on port ${this.#port}`)
})

process.stderr.on('data', (data) => {
if (this.#loggingEnabled) {
console.log(data.toString())
log.info(data.toString())
}
})

Expand Down
7 changes: 5 additions & 2 deletions src/extension/survey.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,9 @@ import { TelemetryReporter } from 'vscode-telemetry'

import { Kernel } from './kernel'
import { isWindows } from './utils'
import getLogger from './logger'

const log = getLogger('WinDefaultShell')

export class WinDefaultShell implements Disposable {
static readonly #id: string = 'runme.surveyWinDefaultShell'
Expand Down Expand Up @@ -85,7 +88,7 @@ export class WinDefaultShell implements Disposable {
unlinkSync(tmpfile)
} catch (err) {
if (err instanceof Error) {
console.log(err.message)
log.error(`Failed to remove temporary default shell: ${err.message}`)
}
}
// eslint-disable-next-line max-len
Expand Down Expand Up @@ -131,7 +134,7 @@ export class WinDefaultShell implements Disposable {
unlinkSync(tmpfile)
} catch (err) {
if (err instanceof Error) {
console.log(err.message)
log.error(`Failed to remove temporary default shell: ${err.message}`)
}
}
}
Expand Down