Add setting for ssh proxy logs

jeanp413 · jeanp413 · commit 9b25868eb758 · 2023-09-27T00:49:58.000-05:00
diff --git a/package.json b/package.json
@@ -67,6 +67,13 @@
 						"type": "number",
 						"description": "The port to use for the local SSH ipc server.",
 						"scope": "application"
+					},
+					"gitpod.lssh.logLevel": {
+						"type": "string",
+						"description": "The log level for ssh proxy.",
+						"scope": "application",
+						"enum": ["none", "debug"],
+						"default": "none"
 					}
 				}
 			}
diff --git a/src/commands/logs.ts b/src/commands/logs.ts
@@ -12,7 +12,9 @@ import { Command } from '../commandManager';
 import { ILogService } from '../services/logService';
 import { INotificationService } from '../services/notificationService';
 import { ITelemetryService, UserFlowTelemetryProperties } from '../common/telemetry';
-import { HostService } from '../services/hostService';
+import { IHostService } from '../services/hostService';
+import { getGitpodRemoteWindowConnectionInfo } from '../remote';
+import SSHDestination from '../ssh/sshDestination';
 
 interface IFile {
 	path: string;
@@ -23,11 +25,12 @@ export class ExportLogsCommand implements Command {
 	readonly id = 'gitpod.exportLogs';
 
 	constructor(
+		private readonly context: vscode.ExtensionContext,
 		private readonly extLocalLogsUri: vscode.Uri,
 		private readonly notificationService: INotificationService,
 		private readonly telemetryService: ITelemetryService,
 		private readonly logService: ILogService,
-		private readonly hostService: HostService,
+		private readonly hostService: IHostService,
 	) { }
 
 	async execute() {
@@ -44,10 +47,28 @@ export class ExportLogsCommand implements Command {
 		}
 	}
 
+	private getAdditionalRemoteLogs() {
+		return [
+			'/tmp/gitpod-git-credential-helper.log',
+			'/var/log/gitpod/supervisor.log',
+			'/workspace/.gitpod/logs/docker-up.log'
+		];
+	}
+
+	private getAdditionalLocalLogs() {
+		const additionalLocalLogs = [];
+		const sshDestStr = getGitpodRemoteWindowConnectionInfo(this.context)?.sshDestStr;
+		if (sshDestStr) {
+			const sshDest = SSHDestination.fromRemoteSSHString(sshDestStr);
+			additionalLocalLogs.push(path.join(os.tmpdir(), `lssh-${sshDest.hostname}.log`));
+		}
+		return additionalLocalLogs;
+	}
+
 	async exportLogs() {
 		const saveUri = await vscode.window.showSaveDialog({
 			title: 'Choose save location ...',
-			defaultUri: vscode.Uri.file(path.posix.join(os.homedir(), `vscode-desktop-logs-${new Date().toISOString().replace(/-|:|\.\d+Z$/g, '')}.zip`)),
+			defaultUri: vscode.Uri.file(path.join(os.homedir(), `vscode-desktop-logs-${new Date().toISOString().replace(/-|:|\.\d+Z$/g, '')}.zip`)),
 		});
 		if (!saveUri) {
 			return;
@@ -61,8 +82,8 @@ export class ExportLogsCommand implements Command {
 			// Ignore if not found
 		}
 
-		const remoteLogsUri = extRemoteLogsUri?.with({ path: path.posix.dirname(path.posix.dirname(extRemoteLogsUri.path)) });
-		const localLogsUri = this.extLocalLogsUri.with({ path: path.posix.dirname(path.posix.dirname(this.extLocalLogsUri.path)) });
+		const remoteLogsUri = extRemoteLogsUri?.with({ path: path.dirname(path.dirname(extRemoteLogsUri.path)) });
+		const localLogsUri = this.extLocalLogsUri.with({ path: path.dirname(path.dirname(this.extLocalLogsUri.path)) });
 
 		return vscode.window.withProgress({
 			location: vscode.ProgressLocation.Notification,
@@ -72,23 +93,19 @@ export class ExportLogsCommand implements Command {
 			const remoteLogFiles: IFile[] = [];
 			if (remoteLogsUri) {
 				await traverseFolder(remoteLogsUri, remoteLogFiles, token);
-				remoteLogFiles.forEach(file => file.path = path.posix.join('./remote', path.posix.relative(remoteLogsUri.path, file.path)));
+				remoteLogFiles.forEach(file => file.path = path.join('./remote', path.relative(remoteLogsUri.path, file.path)));
 				if (token.isCancellationRequested) {
 					return;
 				}
 			}
 
-			for (const logFilePath of [
-				'/tmp/gitpod-git-credential-helper.log',
-				'/var/log/gitpod/supervisor.log',
-				'/workspace/.gitpod/logs/docker-up.log'
-			]) {
+			for (const logFilePath of this.getAdditionalRemoteLogs()) {
 				try {
-					const logFileUri = vscode.Uri.file(logFilePath).with({ scheme: "vscode-remote" });
-					const fileContent = await vscode.workspace.fs.readFile(logFileUri)
+					const logFileUri = vscode.Uri.file(logFilePath).with({ scheme: 'vscode-remote' });
+					const fileContent = await vscode.workspace.fs.readFile(logFileUri);
 					if (fileContent.byteLength > 0) {
 						remoteLogFiles.push({
-							path: path.posix.join('./remote', path.posix.basename(logFileUri.path)),
+							path: path.join('./remote', path.basename(logFileUri.path)),
 							contents: Buffer.from(fileContent)
 						});
 					}
@@ -99,11 +116,26 @@ export class ExportLogsCommand implements Command {
 
 			const localLogFiles: IFile[] = [];
 			await traverseFolder(localLogsUri, localLogFiles, token);
-			localLogFiles.forEach(file => file.path = path.posix.join('./local', path.posix.relative(localLogsUri.path, file.path)));
+			localLogFiles.forEach(file => file.path = path.join('./local', path.relative(localLogsUri.path, file.path)));
 			if (token.isCancellationRequested) {
 				return;
 			}
 
+			for (const logFilePath of this.getAdditionalLocalLogs()) {
+				try {
+					const logFileUri = vscode.Uri.file(logFilePath);
+					const fileContent = await vscode.workspace.fs.readFile(logFileUri);
+					if (fileContent.byteLength > 0) {
+						remoteLogFiles.push({
+							path: path.join('./local', path.basename(logFileUri.path)),
+							contents: Buffer.from(fileContent)
+						});
+					}
+				} catch {
+					// no-op
+				}
+			}
+
 			return zip(saveUri.fsPath, remoteLogFiles.concat(localLogFiles));
 		});
 	}
diff --git a/src/configuration.ts b/src/configuration.ts
@@ -25,8 +25,13 @@ function getLocalSshExtensionIpcPort() {
     return vscode.workspace.getConfiguration('gitpod').get<number>('lsshExtensionIpcPort') || defaultPort;
 }
 
+function getSSHProxyLogLevel() {
+    return vscode.workspace.getConfiguration('gitpod').get<string>('lssh.logLevel') || 'none';
+}
+
 export const Configuration = {
     getGitpodHost,
     getUseLocalApp,
     getLocalSshExtensionIpcPort,
+    getSSHProxyLogLevel
 };
diff --git a/src/extension.ts b/src/extension.ts
@@ -117,7 +117,7 @@ export async function activate(context: vscode.ExtensionContext) {
 		// Register global commands
 		commandManager.register(new SignInCommand(sessionService));
 		commandManager.register(new InstallLocalExtensionsOnRemoteCommand(remoteService));
-		commandManager.register(new ExportLogsCommand(context.logUri, notificationService, telemetryService, logger, hostService));
+		commandManager.register(new ExportLogsCommand(context, context.logUri, notificationService, telemetryService, logger, hostService));
 
 		if (!context.globalState.get<boolean>(FIRST_INSTALL_KEY, false)) {
 			context.globalState.update(FIRST_INSTALL_KEY, true);
diff --git a/src/local-ssh/logger.ts b/src/local-ssh/logger.ts
@@ -3,7 +3,7 @@
  *  Licensed under the MIT License. See License.txt in the project root for license information.
  *--------------------------------------------------------------------------------------------*/
 
-import { WriteStream, createWriteStream } from 'fs';
+import * as fs from 'fs';
 import { inspect } from 'util';
 import { ILogService } from '../services/logService';
 
@@ -17,13 +17,13 @@ export class NopeLogger implements ILogService {
 }
 
 export class DebugLogger implements ILogService {
-    private readonly stream?: WriteStream;
+    private readonly stream?: fs.WriteStream;
 
-    constructor() {
+    constructor(logFilePath: string) {
         try {
             // no need to consider target file for different platform
             // since we use in only for debug local ssh proxy
-            this.stream = createWriteStream('/tmp/lssh.log');
+            this.stream = fs.createWriteStream(logFilePath, { flags: 'a' });
         } catch (_e) { }
     }
 
@@ -32,28 +32,28 @@ export class DebugLogger implements ILogService {
     }
 
     trace(message: string, ...args: any[]): void {
-        this.stream?.write(`${new Date()}TRACE: ${message} ${this.parseArgs(...args)}\n`);
+        this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] TRACE: ${message} ${this.parseArgs(...args)}\n`);
     }
 
     debug(message: string, ...args: any[]): void {
-        this.stream?.write(`${new Date()}DEBUG: ${message} ${this.parseArgs(...args)}\n`);
+        this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] DEBUG: ${message} ${this.parseArgs(...args)}\n`);
     }
 
     info(message: string, ...args: any[]): void {
-        this.stream?.write(`${new Date()}INFO: ${message} ${this.parseArgs(...args)}\n`);
+        this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] INFO: ${message} ${this.parseArgs(...args)}\n`);
     }
 
     warn(message: string, ...args: any[]): void {
-        this.stream?.write(`${new Date()}WARN: ${message} ${this.parseArgs(...args)}\n`);
+        this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] WARN: ${message} ${this.parseArgs(...args)}\n`);
     }
 
     error(error: string | Error, ...args: any[]): void {
         if (error instanceof Error) {
-            this.stream?.write(`${new Date()}ERROR: ${error.toString()}\n${error.stack}\n${this.parseArgs(...args)}\n`);
+            this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] ERROR: ${error.toString()}\n${error.stack}\n${this.parseArgs(...args)}\n`);
         } else {
-            this.stream?.write(`${new Date()}ERROR: ${error.toString()} ${this.parseArgs(...args)}\n`);
+            this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] ERROR: ${error.toString()} ${this.parseArgs(...args)}\n`);
         }
     }
 
     show(): void { }
-}
+}
diff --git a/src/local-ssh/proxy.ts b/src/local-ssh/proxy.ts
@@ -3,21 +3,29 @@
  *  Licensed under the MIT License. See License.txt in the project root for license information.
  *--------------------------------------------------------------------------------------------*/
 
+import * as os from 'os';
+import * as path from 'path';
+
 interface ClientOptions {
     host: string;
+    gitpodHost: string;
     extIpcPort: number;
     machineID: string;
+    debug: boolean;
 }
 
 function getClientOptions(): ClientOptions {
     const args = process.argv.slice(2);
     // %h is in the form of <ws_id>.vss.<gitpod_host>'
     // add `https://` prefix since our gitpodHost is actually a url not host
-    const host = 'https://' + args[0].split('.').splice(2).join('.');
+    const host = args[0];
+    const gitpodHost = 'https://' + args[0].split('.').splice(2).join('.');
     return {
         host,
+        gitpodHost,
         extIpcPort: Number.parseInt(args[1], 10),
         machineID: args[2] ?? '',
+        debug: args[3] === 'debug',
     };
 }
 
@@ -26,26 +34,22 @@ if (!options) {
     process.exit(1);
 }
 
-import { NopeLogger } from './logger';
-const logService = new NopeLogger();
-
-// DO NOT PUSH CHANGES BELOW TO PRODUCTION
-// import { DebugLogger } from './logger';
-// const logService = new DebugLogger();
+import { NopeLogger, DebugLogger } from './logger';
+const logService = options.debug ? new DebugLogger(path.join(os.tmpdir(), `lssh-${options.host}.log`)) : new NopeLogger();
 
 import { TelemetryService } from './telemetryService';
 const telemetryService = new TelemetryService(
     process.env.SEGMENT_KEY!,
     options.machineID,
     process.env.EXT_NAME!,
     process.env.EXT_VERSION!,
-    options.host,
+    options.gitpodHost,
     logService
 );
 
 const flow: SSHUserFlowTelemetry = {
     flow: 'local_ssh',
-    gitpodHost: options.host,
+    gitpodHost: options.gitpodHost,
     workspaceId: '',
     processId: process.pid,
 };
@@ -71,7 +75,7 @@ const exitProcess = async (forceExit: boolean, signal?: NodeJS.Signals) => {
 };
 
 import { SshClient } from '@microsoft/dev-tunnels-ssh-tcp';
-import { NodeStream, ObjectDisposedError, SshChannelError, SshChannelOpenFailureReason, SshClientCredentials, SshClientSession, SshConnectionError, SshDisconnectReason, SshReconnectError, SshReconnectFailureReason, SshServerSession, SshSessionConfiguration, Stream, WebSocketStream } from '@microsoft/dev-tunnels-ssh';
+import { NodeStream, ObjectDisposedError, SshChannelError, SshChannelOpenFailureReason, SshClientCredentials, SshClientSession, SshConnectionError, SshDisconnectReason, SshReconnectError, SshReconnectFailureReason, SshServerSession, SshSessionConfiguration, Stream, TraceLevel, WebSocketStream } from '@microsoft/dev-tunnels-ssh';
 import { importKey, importKeyBytes } from '@microsoft/dev-tunnels-ssh-keys';
 import { ExtensionServiceDefinition, GetWorkspaceAuthInfoResponse } from '../proto/typescript/ipc/v1/ipc';
 import { Client, ClientError, Status, createChannel, createClient } from 'nice-grpc';
@@ -165,6 +169,7 @@ class WebSocketSSHProxy {
             // Seems there's a bug in the ssh library that could hang forever when the stream gets closed
             // so the below `await pipePromise` will never return and the node process will never exit.
             // So let's just force kill here
+            pipeSession?.close(SshDisconnectReason.byApplication);
             setTimeout(() => {
                 exitProcess(true);
             }, 50);
@@ -180,17 +185,22 @@ class WebSocketSSHProxy {
         const keys = await importKeyBytes(getHostKey());
         const config = new SshSessionConfiguration();
         config.maxClientAuthenticationAttempts = 1;
-        const session = new SshServerSession(config);
-        session.credentials.publicKeys.push(keys);
+        const localSession = new SshServerSession(config);
+        localSession.credentials.publicKeys.push(keys);
+        localSession.trace = (_: TraceLevel, eventId: number, msg: string, err?: Error) => {
+            this.logService.trace(`sshsession [local] eventId[${eventId}]`, msg, err);
+        };
 
+        let pipeSession: SshClientSession | undefined;
         let pipePromise: Promise<void> | undefined;
-        session.onAuthenticating(async (e) => {
+        localSession.onAuthenticating(async (e) => {
             this.flow.workspaceId = e.username ?? '';
             this.sendUserStatusFlow('connecting');
             e.authenticationPromise = this.authenticateClient(e.username ?? '')
-                .then(async pipeSession => {
+                .then(async session => {
                     this.sendUserStatusFlow('connected');
-                    pipePromise = session.pipe(pipeSession);
+                    pipeSession = session;
+                    pipePromise = localSession.pipe(pipeSession);
                     return {};
                 }).catch(async err => {
                     this.logService.error('failed to authenticate proxy with username: ' + e.username ?? '', err);
@@ -209,21 +219,21 @@ class WebSocketSSHProxy {
                     // Await a few seconds to delay showing ssh extension error modal dialog
                     await timeout(5000);
 
-                    await session.close(SshDisconnectReason.byApplication, err.toString(), err instanceof Error ? err : undefined);
+                    await localSession.close(SshDisconnectReason.byApplication, err.toString(), err instanceof Error ? err : undefined);
                     return null;
                 });
         });
         try {
-            await session.connect(new NodeStream(sshStream));
+            await localSession.connect(new NodeStream(sshStream));
             await pipePromise;
         } catch (e) {
-            if (session.isClosed) {
+            if (localSession.isClosed) {
                 return;
             }
             e = fixSSHErrorName(e);
             this.logService.error(e, 'failed to connect to client');
             this.sendErrorReport(this.flow, e, 'failed to connect to client');
-            await session.close(SshDisconnectReason.byApplication, e.toString(), e instanceof Error ? e : undefined);
+            await localSession.close(SshDisconnectReason.byApplication, e.toString(), e instanceof Error ? e : undefined);
         }
     }
 
@@ -325,6 +335,9 @@ class WebSocketSSHProxy {
             const config = new SshSessionConfiguration();
             const session = new SshClientSession(config);
             session.onAuthenticating((e) => e.authenticationPromise = Promise.resolve({}));
+            session.trace = (_: TraceLevel, eventId: number, msg: string, err?: Error) => {
+                this.logService.trace(`sshsession [websocket] eventId[${eventId}]`, msg, err);
+            };
 
             await session.connect(stream);
 
@@ -340,7 +353,7 @@ class WebSocketSSHProxy {
 
     async retryGetWorkspaceInfo(username: string) {
         return retry(async () => {
-            return this.extensionIpc.getWorkspaceAuthInfo({ workspaceId: username, gitpodHost: this.options.host }).catch(e => {
+            return this.extensionIpc.getWorkspaceAuthInfo({ workspaceId: username, gitpodHost: this.options.gitpodHost }).catch(e => {
                 let failureCode = 'FailedToGetAuthInfo';
                 if (e instanceof ClientError) {
                     if (e.code === Status.FAILED_PRECONDITION && e.message.includes('gitpod host mismatch')) {
@@ -377,7 +390,7 @@ const metricsReporter = new LocalSSHMetricsReporter(logService);
 const proxy = new WebSocketSSHProxy(options, telemetryService, metricsReporter, logService, flow);
 proxy.start().catch(e => {
     const err = new WrapError('Uncaught exception on start method', e);
-    telemetryService.sendTelemetryException(err, { gitpodHost: options.host });
+    telemetryService.sendTelemetryException(err, { gitpodHost: options.gitpodHost });
 });
 
 function fixSSHErrorName(err: any) {
diff --git a/src/services/remoteService.ts b/src/services/remoteService.ts
diff --git a/src/ssh/sshDestination.ts b/src/ssh/sshDestination.ts

Original file line number	Diff line number	Diff line change
`@@ -67,6 +67,13 @@`
`67`	`67`	`"type": "number",`
`68`	`68`	`"description": "The port to use for the local SSH ipc server.",`
`69`	`69`	`"scope": "application"`
	`70`	`+ },`
	`71`	`+ "gitpod.lssh.logLevel": {`
	`72`	`+ "type": "string",`
	`73`	`+ "description": "The log level for ssh proxy.",`
	`74`	`+ "scope": "application",`
	`75`	`+ "enum": ["none", "debug"],`
	`76`	`+ "default": "none"`
`70`	`77`	`}`
`71`	`78`	`}`
`72`	`79`	`}`
Original file line number	Diff line number	Diff line change
`@@ -3,7 +3,7 @@`
`3`	`3`	`* Licensed under the MIT License. See License.txt in the project root for license information.`
`4`	`4`	`--------------------------------------------------------------------------------------------/`
`5`	`5`
`6`		`-import { WriteStream, createWriteStream } from 'fs';`
	`6`	`+import * as fs from 'fs';`
`7`	`7`	`import { inspect } from 'util';`
`8`	`8`	`import { ILogService } from '../services/logService';`
`9`	`9`
`@@ -17,13 +17,13 @@ export class NopeLogger implements ILogService {`
`17`	`17`	`}`
`18`	`18`
`19`	`19`	`export class DebugLogger implements ILogService {`
`20`		`- private readonly stream?: WriteStream;`
	`20`	`+ private readonly stream?: fs.WriteStream;`
`21`	`21`
`22`		`- constructor() {`
	`22`	`+ constructor(logFilePath: string) {`
`23`	`23`	`try {`
`24`	`24`	`// no need to consider target file for different platform`
`25`	`25`	`// since we use in only for debug local ssh proxy`
`26`		`- this.stream = createWriteStream('/tmp/lssh.log');`
	`26`	`+ this.stream = fs.createWriteStream(logFilePath, { flags: 'a' });`
`27`	`27`	`} catch (_e) { }`
`28`	`28`	`}`
`29`	`29`
`@@ -32,28 +32,28 @@ export class DebugLogger implements ILogService {`
`32`	`32`	`}`
`33`	`33`
`34`	`34`	`trace(message: string, ...args: any[]): void {`
`35`		- this.stream?.write(`${new Date()}TRACE: ${message} ${this.parseArgs(...args)}\n`);
	`35`	+ this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] TRACE: ${message} ${this.parseArgs(...args)}\n`);
`36`	`36`	`}`
`37`	`37`
`38`	`38`	`debug(message: string, ...args: any[]): void {`
`39`		- this.stream?.write(`${new Date()}DEBUG: ${message} ${this.parseArgs(...args)}\n`);
	`39`	+ this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] DEBUG: ${message} ${this.parseArgs(...args)}\n`);
`40`	`40`	`}`
`41`	`41`
`42`	`42`	`info(message: string, ...args: any[]): void {`
`43`		- this.stream?.write(`${new Date()}INFO: ${message} ${this.parseArgs(...args)}\n`);
	`43`	+ this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] INFO: ${message} ${this.parseArgs(...args)}\n`);
`44`	`44`	`}`
`45`	`45`
`46`	`46`	`warn(message: string, ...args: any[]): void {`
`47`		- this.stream?.write(`${new Date()}WARN: ${message} ${this.parseArgs(...args)}\n`);
	`47`	+ this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] WARN: ${message} ${this.parseArgs(...args)}\n`);
`48`	`48`	`}`
`49`	`49`
`50`	`50`	`error(error: string \| Error, ...args: any[]): void {`
`51`	`51`	`if (error instanceof Error) {`
`52`		- this.stream?.write(`${new Date()}ERROR: ${error.toString()}\n${error.stack}\n${this.parseArgs(...args)}\n`);
	`52`	+ this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] ERROR: ${error.toString()}\n${error.stack}\n${this.parseArgs(...args)}\n`);
`53`	`53`	`} else {`
`54`		- this.stream?.write(`${new Date()}ERROR: ${error.toString()} ${this.parseArgs(...args)}\n`);
	`54`	+ this.stream?.write(`${new Date().toISOString()} pid[${process.pid}] ERROR: ${error.toString()} ${this.parseArgs(...args)}\n`);
`55`	`55`	`}`
`56`	`56`	`}`
`57`	`57`
`58`	`58`	`show(): void { }`
`59`		`-}`
	`59`	`+}`