Capture tshd logs (gravitational#853)

web/packages/teleterm/package.json

@@ -48,6 +48,7 @@
     "immer": "^9.0.7",
     "react-dnd": "^14.0.4",
     "react-dnd-html5-backend": "^14.0.2",
+    "split2": "4.1.0",
     "url-loader": "^4.1.1",
     "winston": "^3.3.3",
     "xterm": "^4.15.0",

web/packages/teleterm/src/logger.ts

@@ -1,51 +1,39 @@
 import * as types from 'teleterm/types';
 
-export class DefaultService {
-  createLogger(loggerName: string): types.Logger {
-    const name = loggerName;
-
-    const log = (level = 'log', ...args) => {
-      console[level](`%c[${name}]`, `color: blue;`, ...args);
-    };
-
-    return {
-      warn(...args: any[]) {
-        log('warn', ...args);
-      },
-
-      info(...args: any[]) {
-        log('info', ...args);
-      },
-
-      error(...args: any[]) {
-        log('error', ...args);
-      },
-    };
-  }
-}
-
 export default class Logger {
+  private static service: types.LoggerService;
   private logger: types.Logger;
 
-  private static service = new DefaultService();
-
-  constructor(context = '') {
-    this.logger = Logger.service.createLogger(context);
-  }
+  // The Logger can be initialized in the top-level scope, but any actual
+  // logging cannot be done in that scope, because we cannot guarantee that
+  // Logger.init has already been called
+  constructor(private context = '') {}
 
   warn(message: string, ...args: any[]) {
-    this.logger.warn(message, ...args);
+    this.getLogger().warn(message, ...args);
   }
 
   info(message: string, ...args: any[]) {
-    this.logger.info(message, ...args);
+    this.getLogger().info(message, ...args);
   }
 
   error(message: string, ...args: any[]) {
-    this.logger.error(message, ...args);
+    this.getLogger().error(message, ...args);
   }
 
   static init(service: types.LoggerService) {
     Logger.service = service;
   }
+
+  private getLogger(): types.Logger {
+    if (!this.logger) {
+      if (!Logger.service) {
+        throw new Error('Logger is not initialized');
+      }
+
+      this.logger = Logger.service.createLogger(this.context);
+    }
+
+    return this.logger;
+  }
 }

web/packages/teleterm/src/main.ts

@@ -11,10 +11,10 @@ import path from 'path';
 import { WindowsManager } from 'teleterm/mainProcess/windowsManager';
 
 const settings = getRuntimeSettings();
+const logger = initMainLogger(settings);
 const fileStorage = createFileStorage({
   filePath: path.join(settings.userDataDir, 'app_state.json'),
 });
-const logger = initMainLogger(settings);
 const configService = new ConfigServiceImpl();
 const windowsManager = new WindowsManager(fileStorage, settings);
 
@@ -99,7 +99,7 @@ function initMainLogger(settings: types.RuntimeSettings) {
   const service = createLoggerService({
     dev: settings.dev,
     dir: settings.userDataDir,
-    name: "main"
+    name: 'main',
   });
 
   Logger.init(service);

web/packages/teleterm/src/mainProcess/mainProcess.ts

@@ -9,6 +9,7 @@ import {
 import { subscribeToTabContextMenuEvent } from './contextMenus/tabContextMenu';
 import { subscribeToFileStorageEvents } from 'teleterm/services/fileStorage';
 import path from 'path';
+import createLoggerService from 'teleterm/services/logger';
 
 type Options = {
   settings: RuntimeSettings;
@@ -58,13 +59,23 @@ export default class MainProcess {
   private _initTshd() {
     const { binaryPath, flags, homeDir } = this.settings.tshd;
     this.tshdProcess = spawn(binaryPath, flags, {
-      stdio: 'inherit',
+      stdio: [null, 'pipe', 'pipe'],
       env: {
         ...process.env,
         TELEPORT_HOME: homeDir,
       },
     });
 
+    const tshdLogger = createLoggerService({
+      dev: this.settings.dev,
+      dir: this.settings.userDataDir,
+      name: 'tshd',
+      passThroughMode: true,
+    });
+
+    tshdLogger.pipeProcessOutputIntoLogger(this.tshdProcess.stdout);
+    tshdLogger.pipeProcessOutputIntoLogger(this.tshdProcess.stderr);
+
     this.tshdProcess.on('error', error => {
       this.logger.error('tshd failed to start', error);
     });

web/packages/teleterm/src/services/logger/loggerService.ts

@@ -1,6 +1,7 @@
 import { createLogger as createWinston, format, transports } from 'winston';
 import { isObject } from 'lodash';
 import { Logger, LoggerService } from './types';
+import split2 from 'split2';
 
 export default function createLoggerService(opts: Options): LoggerService {
   const instance = createWinston({
@@ -12,14 +13,17 @@ export default function createLoggerService(opts: Options): LoggerService {
       }),
       format.printf(({ level, message, timestamp, context }) => {
         const text = stringifier(message as unknown as unknown[]);
-        return `[${timestamp}] [${context}] ${level}: ${text}`;
+        const contextAndLevel = opts.passThroughMode
+          ? ''
+          : ` [${context}] ${level}`;
+        return `[${timestamp}]${contextAndLevel}: ${text}`;
       })
     ),
     transports: [
       new transports.File({
         maxsize: 4194304, // 4 MB - max size of a single file
         maxFiles: 5,
-        dirname: opts.dir,
+        dirname: opts.dir + '/logs',
         filename: `${opts.name}.log`,
       }),
     ],
@@ -30,13 +34,18 @@ export default function createLoggerService(opts: Options): LoggerService {
       new transports.Console({
         format: format.printf(({ level, message, context }) => {
           const text = stringifier(message as unknown as unknown[]);
-          return `[${context}] ${level}: ${text}`;
+          return opts.passThroughMode ? text : `[${context}] ${level}: ${text}`;
         }),
       })
     );
   }
 
   return {
+    pipeProcessOutputIntoLogger(stream): void {
+      stream
+        .pipe(split2(line => ({ level: 'info', message: [line] })))
+        .pipe(instance);
+    },
     createLogger(context = 'default'): Logger {
       const logger = instance.child({ context });
       return {
@@ -72,4 +81,8 @@ type Options = {
   dir: string;
   name: string;
   dev?: boolean;
+  /**
+   * Mode for logger handling logs from other sources. Log level and context are not included in the log message.
+   */
+  passThroughMode?: boolean;
 };

web/packages/teleterm/src/services/logger/types.ts

@@ -1,9 +1,12 @@
+import { Stream } from 'stream';
+
 export interface Logger {
   error(...args: unknown[]): void;
   warn(...args: unknown[]): void;
   info(...args: unknown[]): void;
 }
 
 export interface LoggerService {
+  pipeProcessOutputIntoLogger(stream: Stream): void;
   createLogger(context: string): Logger;
 }

web/packages/teleterm/src/services/pty/ptyHost/resolveShellEnv.ts

@@ -40,7 +40,7 @@
 
 // Based on https://github.com/microsoft/vscode/blob/1.66.0/src/vs/platform/shell/node/shellEnv.ts
 
-import { Logger } from 'shared/libs/logger';
+import Logger from 'teleterm/logger';
 import { unique } from 'teleterm/ui/utils/uid';
 import { spawn } from 'child_process';
 import { memoize } from 'lodash';
@@ -50,9 +50,11 @@ const resolveShellMaxTime = 8000; // 8s
 
 export const resolveShellEnvCached = memoize(resolveShellEnv);
 
-async function resolveShellEnv(shell: string): Promise<typeof process.env | undefined> {
+async function resolveShellEnv(
+  shell: string
+): Promise<typeof process.env | undefined> {
   if (process.platform === 'win32') {
-    logger.trace('skipped Windows platform');
+    logger.info('skipped Windows platform');
     return;
   }
   // TODO(grzegorz) skip if already running from CLI
@@ -91,7 +93,7 @@ async function resolveUnixShellEnv(
     // https://unix.stackexchange.com/questions/277312/is-the-shell-created-by-bash-i-c-command-interactive
     const shellArgs = shell === '/bin/tcsh' ? ['-ic'] : ['-ilc'];
 
-    logger.trace(`Reading shell ${shell} ${shellArgs} ${command}`);
+    logger.info(`Reading shell ${shell} ${shellArgs} ${command}`);
 
     const child = spawn(shell, [...shellArgs, command], {
       detached: true,

web/packages/teleterm/src/services/tshd/middleware.test.ts

@@ -5,6 +5,7 @@ import Logger from 'teleterm/logger';
 it('do not log sensitive info like password', () => {
   const infoLogger = jest.fn();
   Logger.init({
+    pipeProcessOutputIntoLogger: () => {},
     createLogger: () => ({
       info: infoLogger,
       error: () => {},

web/packages/teleterm/src/ui/DocumentTerminal/Terminal/ctrl.ts

@@ -19,7 +19,7 @@ import { IDisposable, Terminal } from 'xterm';
 import { FitAddon } from 'xterm-addon-fit';
 import { debounce } from 'lodash';
 import { IPtyProcess } from 'teleterm/sharedProcess/ptyHost';
-import Logger from 'teleterm/ui/logger';
+import Logger from 'teleterm/logger';
 import theme from 'teleterm/ui/ThemeProvider/theme';
 
 const WINDOW_RESIZE_DEBOUNCE_DELAY = 200;

web/packages/teleterm/src/ui/boot.tsx

@@ -3,10 +3,10 @@ import React from 'react';
 import { ElectronGlobals } from 'teleterm/types';
 import App from 'teleterm/ui/App';
 import AppContext from 'teleterm/ui/appContext';
-import Logger, { initLogger } from 'teleterm/ui/logger';
+import Logger from 'teleterm/logger';
 
 const globals = window['electron'] as ElectronGlobals;
-initLogger(globals);
+Logger.init(globals.loggerService);
 
 const logger = new Logger('UI');
 const appContext = new AppContext(globals);

web/packages/teleterm/src/ui/components/CatchError/CatchError.jsx

@@ -16,7 +16,7 @@ limitations under the License.
 
 import React from 'react';
 import { Failed } from 'design/CardError';
-import Logger from 'teleterm/ui/logger';
+import Logger from 'teleterm/logger';
 
 export default class CatchError extends React.Component {
   logger = new Logger('components/CatchError');

web/packages/teleterm/src/ui/fixtures/mocks.ts

@@ -21,6 +21,7 @@ export class MockAppContext extends AppContext {
 
 function createLoggerService() {
   return {
+    pipeProcessOutputIntoLogger() {},
     createLogger() {
       return {
         error: () => {},

web/packages/teleterm/src/ui/services/immutableStore/immutableStore.ts

@@ -3,7 +3,7 @@
 import { enableMapSet, produce } from 'immer';
 import Store from 'shared/libs/stores/store';
 import stateLogger from 'shared/libs/stores/logger';
-import Logger from 'teleterm/ui/logger';
+import Logger from 'teleterm/logger';
 
 enableMapSet();
 

web/yarn.lock

@@ -5690,7 +5690,7 @@ delegates@^1.0.0:
 depd@^1.1.2, depd@~1.1.2:
   version "1.1.2"
   resolved "https://registry.yarnpkg.com/depd/-/depd-1.1.2.tgz#9bcd52e14c097763e749b274c4346ed2e560b5a9"
-  integrity sha1-m81S4UwJd2PnSbJ0xDRu0uVgtak=
+  integrity sha512-7emPTl6Dpo6JRXOXjLRxck+FlLRX5847cLKEn00PLAgc3g2hTZZgr+e4c2v6QpSmLeFP3n5yUo7ft6avBK/5jQ==
 
 des.js@^1.0.0:
   version "1.0.1"
@@ -7983,7 +7983,7 @@ human-signals@^2.1.0:
 humanize-ms@^1.2.1:
   version "1.2.1"
   resolved "https://registry.yarnpkg.com/humanize-ms/-/humanize-ms-1.2.1.tgz#c46e3159a293f6b896da29316d8b6fe8bb79bbed"
-  integrity sha1-xG4xWaKT9riW2ikxbYtv6Lt5u+0=
+  integrity sha512-Fl70vYtsAFb/C06PTS9dZBo7ihau+Tu/DNCk/OyHhea07S+aeMWpFFkUaXRa8fI+ScZbEI8dfSxwY7gxZ9SAVQ==
   dependencies:
     ms "^2.0.0"
 
@@ -8392,7 +8392,7 @@ is-installed-globally@^0.4.0:
 is-lambda@^1.0.1:
   version "1.0.1"
   resolved "https://registry.yarnpkg.com/is-lambda/-/is-lambda-1.0.1.tgz#3d9877899e6a53efc0160504cde15f82e6f061d5"
-  integrity sha1-PZh3iZ5qU+/AFgUEzeFfgubwYdU=
+  integrity sha512-z7CMFGNrENq5iFB9Bqo64Xk6Y9sg+epq1myIcdHaGnbMTYOxvzsEtdYqQUylB7LxfkvgrrjP32T6Ywciio9UIQ==
 
 is-map@^2.0.2:
   version "2.0.2"
@@ -12711,6 +12711,11 @@ split-string@^3.0.1, split-string@^3.0.2:
   dependencies:
     extend-shallow "^3.0.0"
 
+[email protected]:
+  version "4.1.0"
+  resolved "https://registry.yarnpkg.com/split2/-/split2-4.1.0.tgz#101907a24370f85bb782f08adaabe4e281ecf809"
+  integrity sha512-VBiJxFkxiXRlUIeyMQi8s4hgvKCSjtknJv/LVYbrgALPwf5zSKmEwV9Lst25AkvMDnvxODugjdl6KZgwKM1WYQ==
+
 sprintf-js@^1.1.2:
   version "1.1.2"
   resolved "https://registry.yarnpkg.com/sprintf-js/-/sprintf-js-1.1.2.tgz#da1765262bf8c0f571749f2ad6c26300207ae673"