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

Slow to update test results in VS Code when using typescript and esbuild #2946

Closed
abirtley opened this issue Mar 10, 2022 · 6 comments
Closed

Comments

@abirtley
Copy link

abirtley commented Mar 10, 2022

Issue description or question

Wallaby is very slow to update test results, largely defeating the purpose of the tool. I often have to make other random changes (like empty newlines) and/or save the file in order for it to update.

The following video illustrates the problem. In particular, notice that the test time keeps updating (so Wallaby is re-running the test) but the results aren't changing (so it appears Wallaby is looking at the wrong code). Sometimes saving the file forces Wallaby to update, but by no means always.

Quokka.slow.to.update.mov

A reproduction repository is available here: https://github.com/abirtley/quokka-slow-typescript-reproduction

I have based this on a https://github.com/serverless-stack/serverless-stack example (specifically, the typescript monorepo example) but pulled out everything but the typescript configuration, jest configuration, and simple code files.

Note that the Wallaby demo worked fine on my computer, and did not have this problem.

I expect it might have something to do with the typescript configuration in this particular project, but I'm not sure what to change in order to make Wallaby happy 😄

Wallaby diagnostics report

{
  editorVersion: '1.65.1',
  pluginVersion: '1.0.328',
  editorType: 'VSCode',
  osVersion: 'darwin 20.6.0',
  nodeVersion: 'v14.17.5',
  coreVersion: '1.0.1240',
  checksum: 'MDI0ODgzYWU0ZGU0OWE4MzlkZTdmZjNiMWZkNjMwZDIsMTY3ODMyMDAwMDAwMCww',
  config: {
    diagnostics: {
      jest: {
        config: {
          configs: [
            {
              automock: false,
              cache: true,
              cacheDirectory: '/private/var/folders/kn/lrcbwj4x5vzfrhw3ln56yjnh0000gn/T/jest_dx',
              clearMocks: false,
              coveragePathIgnorePatterns: [ '/node_modules/' ],
              cwd: '<homeDir>/Desktop/backend',
              dependencyExtractor: undefined,
              detectLeaks: false,
              detectOpenHandles: false,
              displayName: undefined,
              errorOnDeprecated: false,
              extensionsToTreatAsEsm: [],
              extraGlobals: [],
              filter: undefined,
              forceCoverageMatch: [],
              globalSetup: undefined,
              globalTeardown: undefined,
              globals: {},
              haste: { computeSha1: false, enableSymlinks: false, forceNodeFilesystemAPI: false, throwOnModuleCollision: false },
              injectGlobals: true,
              moduleDirectories: [ 'node_modules' ],
              moduleFileExtensions: [ 'js', 'jsx', 'ts', 'tsx', 'json', 'node' ],
              moduleLoader: undefined,
              moduleNameMapper: [],
              modulePathIgnorePatterns: [],
              modulePaths: undefined,
              name: 'f946aaa334fb52027a2741a323b2407b',
              prettierPath: 'prettier',
              resetMocks: false,
              resetModules: false,
              resolver: undefined,
              restoreMocks: false,
              rootDir: '<homeDir>/Desktop/backend',
              roots: [ '<homeDir>/Desktop/backend/test' ],
              runner: '<homeDir>/Desktop/backend/node_modules/jest-cli/node_modules/jest-runner/build/index.js',
              setupFiles: [],
              setupFilesAfterEnv: [ '<homeDir>/Desktop/backend/test/jest.setup.ts' ],
              skipFilter: false,
              skipNodeResolution: undefined,
              slowTestThreshold: 5,
              snapshotFormat: undefined,
              snapshotResolver: undefined,
              snapshotSerializers: [],
              testEnvironment: '<homeDir>/Desktop/backend/node_modules/jest-environment-node/build/index.js',
              testEnvironmentOptions: {},
              testLocationInResults: false,
              testMatch: [ '**/*.*test.(ts|tsx|js)' ],
              testPathIgnorePatterns: [ '/node_modules/' ],
              testRegex: [],
              testRunner: '<homeDir>/Desktop/backend/node_modules/jest-circus/runner.js',
              testURL: 'http://localhost',
              timers: 'real',
              transform: [ [ '\\.ts$', '<homeDir>/Desktop/backend/node_modules/esbuild-runner/jest.js', {} ] ],
              transformIgnorePatterns: [ '/node_modules/', '\\.pnp\\.[^\\/]+$' ],
              unmockedModulePathPatterns: undefined,
              watchPathIgnorePatterns: []
            }
          ],
          globalConfig: {
            bail: 0,
            changedFilesWithAncestor: false,
            changedSince: undefined,
            collectCoverage: true,
            collectCoverageFrom: [ '(functions|core|services)/**/*.{ts,js}' ],
            collectCoverageOnlyFrom: undefined,
            coverageDirectory: '<homeDir>/Desktop/backend/coverage',
            coverageProvider: 'babel',
            coverageReporters: [ 'json', 'text', 'lcov', 'clover' ],
            coverageThreshold: undefined,
            detectLeaks: false,
            detectOpenHandles: false,
            errorOnDeprecated: false,
            expand: false,
            filter: undefined,
            findRelatedTests: false,
            forceExit: false,
            globalSetup: undefined,
            globalTeardown: undefined,
            json: false,
            lastCommit: false,
            listTests: false,
            logHeapUsage: false,
            maxConcurrency: 5,
            maxWorkers: 7,
            noSCM: undefined,
            noStackTrace: false,
            nonFlagArgs: undefined,
            notify: false,
            notifyMode: 'failure-change',
            onlyChanged: false,
            onlyFailures: false,
            outputFile: undefined,
            passWithNoTests: false,
            projects: [],
            replname: undefined,
            reporters: undefined,
            rootDir: '<homeDir>/Desktop/backend',
            runTestsByPath: false,
            silent: undefined,
            skipFilter: false,
            snapshotFormat: undefined,
            testFailureExitCode: 1,
            testNamePattern: undefined,
            testPathPattern: '',
            testResultsProcessor: undefined,
            testSequencer: '<homeDir>/Desktop/backend/node_modules/jest-cli/node_modules/@jest/test-sequencer/build/index.js',
            testTimeout: undefined,
            updateSnapshot: 'new',
            useStderr: false,
            verbose: undefined,
            watch: false,
            watchAll: false,
            watchPlugins: undefined,
            watchman: true
          },
          hasDeprecationWarnings: false,
          wallaby: {
            roots: [ 'test' ],
            watchPathIgnorePatterns: [ '/node_modules/', '\\./dist/|\\./build/|\\./coverage/|\\./git/|/\\..+/', '/private/var/folders/kn/lrcbwj4x5vzfrhw3ln56yjnh0000gn/T/jest_dx', '\\./coverage' ],
            testPathIgnorePatterns: [ '/node_modules/', '\\./dist/|\\./build/|\\./coverage/|\\./git/|/\\..+/', '/private/var/folders/kn/lrcbwj4x5vzfrhw3ln56yjnh0000gn/T/jest_dx', '\\./coverage' ],
            testMatch: [ '**/*.*test.(ts|tsx|js)' ],
            testRegex: []
          }
        }
      }
    },
    testFramework: { version: 'jest@24.8.0', configurator: 'jest@24.8.0', reporter: 'jest@24.8.0', starter: 'jest@24.8.0', autoDetected: true },
    filesWithCoverageCalculated: [ '(functions|core|services)/**/*.{ts,js}' ],
    filesWithNoCoverageCalculated: [],
    globalSetup: false,
    micromatch: true,
    files: [
      { pattern: '/node_modules/', regexp: /\/node_modules\//, ignore: true, trigger: true, load: true },
      { pattern: '\\./dist/|\\./build/|\\./coverage/|\\./git/|/\\..+/', regexp: /\.\/dist\/|\.\/build\/|\.\/coverage\/|\.\/git\/|\/\..+\//, ignore: true, trigger: true, load: true },
      {
        pattern: '/private/var/folders/kn/lrcbwj4x5vzfrhw3ln56yjnh0000gn/T/jest_dx',
        regexp: /\/private\/var\/folders\/kn\/lrcbwj4x5vzfrhw3ln56yjnh0000gn\/T\/jest_dx/,
        ignore: true,
        trigger: true,
        load: true
      },
      { pattern: '\\./coverage', regexp: /\.\/coverage/, ignore: true, trigger: true, load: true },
      { pattern: '**/**', ignore: false, trigger: true, load: true, order: 1 },
      { pattern: 'test/**', ignore: false, trigger: true, load: true, order: 2 },
      { pattern: 'test/**/*.*test.(ts|tsx|js)', ignore: true, trigger: true, load: true }
    ],
    tests: [
      { pattern: '/node_modules/', regexp: /\/node_modules\//, ignore: true, trigger: true, load: true, test: true },
      {
        pattern: '\\./dist/|\\./build/|\\./coverage/|\\./git/|/\\..+/',
        regexp: /\.\/dist\/|\.\/build\/|\.\/coverage\/|\.\/git\/|\/\..+\//,
        ignore: true,
        trigger: true,
        load: true,
        test: true
      },
      {
        pattern: '/private/var/folders/kn/lrcbwj4x5vzfrhw3ln56yjnh0000gn/T/jest_dx',
        regexp: /\/private\/var\/folders\/kn\/lrcbwj4x5vzfrhw3ln56yjnh0000gn\/T\/jest_dx/,
        ignore: true,
        trigger: true,
        load: true,
        test: true
      },
      { pattern: '\\./coverage', regexp: /\.\/coverage/, ignore: true, trigger: true, load: true, test: true },
      { pattern: 'test/**/*.*test.(ts|tsx|js)', ignore: false, trigger: true, load: true, test: true, order: 3 }
    ],
    runAllTestsInAffectedTestFile: false,
    updateNoMoreThanOneSnapshotPerTestFileRun: false,
    addModifiedTestFileToExclusiveTestRun: true,
    compilers: {},
    preprocessors: {},
    maxConsoleMessagesPerTest: 100,
    autoConsoleLog: true,
    delays: { run: 0, edit: 100, update: 0 },
    workers: { initial: 0, regular: 0, recycle: false },
    teardown: undefined,
    hints: {
      ignoreCoverage: '__REGEXP /ignore coverage|istanbul ignore/',
      ignoreCoverageForFile: '__REGEXP /ignore file coverage/',
      commentAutoLog: '?',
      testFileSelection: { include: '__REGEXP /file\\.only/', exclude: '__REGEXP /file\\.skip/' }
    },
    automaticTestFileSelection: true,
    runSelectedTestsOnly: false,
    mapConsoleMessagesStackTrace: false,
    extensions: {},
    env: {
      type: 'node',
      params: {},
      runner: '<homeDir>/.nvm/versions/node/v14.17.5/bin/node',
      viewportSize: { width: 800, height: 600 },
      options: { width: 800, height: 600 },
      bundle: true
    },
    reportUnhandledPromises: true,
    slowTestThreshold: 75,
    lowCoverageThreshold: 80,
    loose: true,
    configCode: 'auto.detect#-1934873199'
  },
  packageJSON: {
    dependencies: {
      '@middy/core': '^2.5.7',
      '@middy/http-error-handler': '^2.5.7',
      '@middy/validator': '^2.5.7',
      '@types/aws-lambda': '^8.10.83',
      arangojs: '^7.7.0',
      'middy-middleware-jwt-auth': '^5.0.0',
      winston: '^3.6.0',
      zod: '^3.13.4'
    },
    devDependencies: {
      '@types/node-fetch': '^2.6.1',
      'aws-sdk': '^2.1084.0',
      'aws-testing-library': '^1.1.6',
      'esbuild-runner': '^2.2.1',
      jest: '^27.2.0',
      'node-fetch': '^2',
      'sls-test-tools': '^1.0.7',
      '@serverless-stack/cli': '0.65.4',
      '@serverless-stack/resources': '0.65.4',
      '@tsconfig/node14': '^1.0.1',
      '@types/ramda': '^0.27.65',
      'aws-cdk-lib': '2.7.0',
      commitizen: '^4.2.4',
      'cz-conventional-changelog': '^3.3.0',
      eslint: '^7.32.0',
      'eslint-config-prettier': '^8.3.0',
      'eslint-plugin-fp': '^2.3.0',
      'eslint-plugin-node': '^11.1.0',
      'eslint-plugin-prettier': '^4.0.0',
      prettier: '^2.5.1',
      ramda: '^0.28.0',
      typescript: '^4.5.5'
    }
  },
  fs: { numberOfFiles: 9 },
  debug: [
    '2022-03-10T00:20:50.544Z angular/cli config Angular CLI not found.\n',
    '2022-03-10T00:20:50.638Z jest/config Detected Jest.\n',
    '2022-03-10T00:20:50.639Z jest/config Configured Jest.\n',
    '2022-03-10T00:20:50.640Z project Wallaby Node version: v14.17.5\n',
    '2022-03-10T00:20:50.640Z project Wallaby config: <homeDir>/Desktop/backend/auto.detect\n',
    '2022-03-10T00:20:50.681Z project File cache: <homeDir>/.vscode/extensions/wallabyjs.wallaby-vscode-1.0.328/projects/4a603ec2b8f23f96\n',
    '2022-03-10T00:20:50.796Z uiService Listening port 51235\n',
    '2022-03-10T00:20:50.804Z project package.json file change detected, invalidating local cache\n',
    '2022-03-10T00:20:50.809Z workers Parallelism for initial run: 6, for regular run: 3\n',
    '2022-03-10T00:20:50.809Z workers Starting run worker instance #0\n',
    '2022-03-10T00:20:50.809Z workers Starting run worker instance wallabyjs/public#1\n',
    '2022-03-10T00:20:50.809Z workers Starting run worker instance wallabyjs/public#2\n',
    '2022-03-10T00:20:50.809Z workers Starting run worker instance wallabyjs/public#3\n',
    '2022-03-10T00:20:50.809Z workers Starting run worker instance wallabyjs/public#4\n',
    '2022-03-10T00:20:50.809Z workers Starting run worker instance wallabyjs/public#5\n',
    '2022-03-10T00:20:50.810Z workers Web server is listening at 54812\n',
    '2022-03-10T00:20:50.810Z project File cache requires some updates, waiting required files from IDE\n',
    '2022-03-10T00:20:50.941Z project Stopping process pool\n',
    '2022-03-10T00:20:50.945Z project Test run started; run priority: 3\n',
    '2022-03-10T00:20:50.947Z project Running all tests\n',
    '2022-03-10T00:20:50.948Z workers Starting test run, priority: 3\n',
    '2022-03-10T00:20:50.954Z nodeRunner Starting sandbox [worker #0, session #oj58l]\n',
    '2022-03-10T00:20:50.954Z nodeRunner Preparing sandbox [worker #0, session #oj58l]\n',
    '2022-03-10T00:20:50.967Z workers Started run worker instance (delayed) #0\n',
    '2022-03-10T00:20:50.968Z nodeRunner Prepared sandbox [worker #0, session #oj58l]\n',
    '2022-03-10T00:20:50.968Z workers [worker #0, session #oj58l] Running tests in sandbox\n',
    '2022-03-10T00:20:51.081Z workers Started run worker instance (delayed) wallabyjs/public#2\n',
    '2022-03-10T00:20:51.087Z workers Started run worker instance (delayed) wallabyjs/public#1\n',
    '2022-03-10T00:20:51.107Z workers Started run worker instance (delayed) wallabyjs/public#3\n',
    '2022-03-10T00:20:51.108Z workers Started run worker instance (delayed) wallabyjs/public#5\n',
    '2022-03-10T00:20:51.133Z workers Started run worker instance (delayed) wallabyjs/public#4\n',
    '2022-03-10T00:20:51.945Z workers Scheduling Jest Test Run (oj58l): 2022-03-10T00:20:51.329Z\n',
    '2022-03-10T00:20:51.949Z workers [oj58l] Loaded unknown number of test(s)\n',
    '2022-03-10T00:20:51.949Z workers [oj58l] Test executed: foo\n',
    '2022-03-10T00:20:51.950Z workers [oj58l] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:20:51.951Z workers Jest Test Run Complete (oj58l): 2022-03-10T00:20:51.944Z\n',
    '2022-03-10T00:20:51.952Z workers [oj58l] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:51.952Z project Test run finished\n',
    '2022-03-10T00:20:51.953Z project Processed console.log entries\n',
    '2022-03-10T00:20:51.953Z project Processed loading sequences\n',
    '2022-03-10T00:20:51.953Z project Processed executed tests\n',
    '2022-03-10T00:20:51.953Z project Processed code coverage\n',
    '2022-03-10T00:20:51.961Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:20:52.147Z uiService UI client connected\n',
    '2022-03-10T00:20:52.147Z uiService Outgoing message ui:handshake\n',
    '2022-03-10T00:20:52.160Z uiService Incoming message ui:tests:resultsRequested\n',
    '2022-03-10T00:20:52.161Z uiService Outgoing message ui:tests:allResultsUpdated\n',
    '2022-03-10T00:20:52.161Z uiService Incoming message ui:start\n',
    '2022-03-10T00:20:52.161Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:52.162Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:54.136Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:20:54.138Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:54.138Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:54.142Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:54.142Z project Test run started; run priority: 2\n',
    '2022-03-10T00:20:54.142Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:20:54.143Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:20:54.143Z nodeRunner Starting sandbox [worker #0, session #cc7ug]\n',
    '2022-03-10T00:20:54.143Z nodeRunner Preparing sandbox [worker #0, session #cc7ug]\n',
    '2022-03-10T00:20:54.143Z nodeRunner Prepared sandbox [worker #0, session #cc7ug]\n',
    '2022-03-10T00:20:54.143Z workers [worker #0, session #cc7ug] Running tests in sandbox\n',
    '2022-03-10T00:20:54.311Z workers Scheduling Jest Test Run (cc7ug): 2022-03-10T00:20:54.145Z\n',
    '2022-03-10T00:20:54.312Z workers [cc7ug] Loaded unknown number of test(s)\n',
    '2022-03-10T00:20:54.313Z workers [cc7ug] Test executed: foo\n',
    '2022-03-10T00:20:54.313Z workers [cc7ug] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:20:54.314Z workers Jest Test Run Complete (cc7ug): 2022-03-10T00:20:54.310Z\n',
    '2022-03-10T00:20:54.314Z workers [cc7ug] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:54.315Z project Test run finished\n',
    '2022-03-10T00:20:54.315Z project Processed console.log entries\n',
    '2022-03-10T00:20:54.315Z project Processed loading sequences\n',
    '2022-03-10T00:20:54.315Z project Processed executed tests\n',
    '2022-03-10T00:20:54.315Z project Processed code coverage\n',
    '2022-03-10T00:20:54.317Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:20:54.317Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:54.317Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:20:54.752Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:20:54.752Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:54.752Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:54.755Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:54.757Z project Test run started; run priority: 2\n',
    '2022-03-10T00:20:54.757Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:20:54.757Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:20:54.757Z nodeRunner Starting sandbox [worker #0, session #bl3uh]\n',
    '2022-03-10T00:20:54.757Z nodeRunner Preparing sandbox [worker #0, session #bl3uh]\n',
    '2022-03-10T00:20:54.757Z nodeRunner Prepared sandbox [worker #0, session #bl3uh]\n',
    '2022-03-10T00:20:54.757Z workers [worker #0, session #bl3uh] Running tests in sandbox\n',
    '2022-03-10T00:20:54.882Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:20:54.883Z workers Cancelling test run, cancel requester priority: 2, current run priority: 2\n',
    '2022-03-10T00:20:54.883Z project Test run was cancelled\n',
    '2022-03-10T00:20:54.883Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:54.884Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:54.884Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:54.911Z workers Scheduling Jest Test Run (bl3uh): 2022-03-10T00:20:54.758Z\n',
    '2022-03-10T00:20:54.916Z workers Jest Test Run Complete (bl3uh): 2022-03-10T00:20:54.911Z\n',
    '2022-03-10T00:20:54.916Z workers [bl3uh] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:54.916Z project Test run cancelled, re-queueing run data\n',
    '2022-03-10T00:20:54.916Z project Test run finished\n',
    '2022-03-10T00:20:54.917Z project Test run data re-queued\n',
    '2022-03-10T00:20:54.917Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:54.938Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:54.938Z project Test run started; run priority: 2\n',
    '2022-03-10T00:20:54.938Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:20:54.939Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:20:54.939Z nodeRunner Starting sandbox [worker #0, session #p7707]\n',
    '2022-03-10T00:20:54.939Z nodeRunner Preparing sandbox [worker #0, session #p7707]\n',
    '2022-03-10T00:20:54.939Z nodeRunner Prepared sandbox [worker #0, session #p7707]\n',
    '2022-03-10T00:20:54.939Z workers [worker #0, session #p7707] Running tests in sandbox\n',
    '2022-03-10T00:20:54.981Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:20:54.982Z workers Cancelling test run, cancel requester priority: 2, current run priority: 2\n',
    '2022-03-10T00:20:54.982Z project Test run was cancelled\n',
    '2022-03-10T00:20:54.982Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:54.982Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:54.984Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:55.036Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:55.077Z workers Scheduling Jest Test Run (p7707): 2022-03-10T00:20:54.940Z\n',
    '2022-03-10T00:20:55.081Z workers Jest Test Run Complete (p7707): 2022-03-10T00:20:55.076Z\n',
    '2022-03-10T00:20:55.081Z workers [p7707] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:55.081Z project Test run cancelled, re-queueing run data\n',
    '2022-03-10T00:20:55.081Z project Test run finished\n',
    '2022-03-10T00:20:55.081Z project Test run data re-queued\n',
    '2022-03-10T00:20:55.082Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:55.087Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:55.090Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:55.090Z project Test run started; run priority: 2\n',
    '2022-03-10T00:20:55.090Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:20:55.090Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:20:55.090Z nodeRunner Starting sandbox [worker #0, session #8lnmc]\n',
    '2022-03-10T00:20:55.090Z nodeRunner Preparing sandbox [worker #0, session #8lnmc]\n',
    '2022-03-10T00:20:55.090Z nodeRunner Prepared sandbox [worker #0, session #8lnmc]\n',
    '2022-03-10T00:20:55.090Z workers [worker #0, session #8lnmc] Running tests in sandbox\n',
    '2022-03-10T00:20:55.224Z workers Scheduling Jest Test Run (8lnmc): 2022-03-10T00:20:55.093Z\n',
    '2022-03-10T00:20:55.225Z workers [8lnmc] Loaded unknown number of test(s)\n',
    '2022-03-10T00:20:55.226Z workers [8lnmc] Test executed: foo\n',
    '2022-03-10T00:20:55.226Z workers [8lnmc] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:20:55.227Z workers Jest Test Run Complete (8lnmc): 2022-03-10T00:20:55.223Z\n',
    '2022-03-10T00:20:55.227Z workers [8lnmc] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:55.228Z project Test run finished\n',
    '2022-03-10T00:20:55.228Z project Processed console.log entries\n',
    '2022-03-10T00:20:55.228Z project Processed loading sequences\n',
    '2022-03-10T00:20:55.228Z project Processed executed tests\n',
    '2022-03-10T00:20:55.228Z project Processed code coverage\n',
    '2022-03-10T00:20:55.229Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:20:55.229Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:55.229Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:20:57.011Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:20:57.012Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:57.012Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:57.014Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:57.016Z project Test run started; run priority: 2\n',
    '2022-03-10T00:20:57.016Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:20:57.016Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:20:57.016Z nodeRunner Starting sandbox [worker #0, session #xbs0q]\n',
    '2022-03-10T00:20:57.016Z nodeRunner Preparing sandbox [worker #0, session #xbs0q]\n',
    '2022-03-10T00:20:57.016Z nodeRunner Prepared sandbox [worker #0, session #xbs0q]\n',
    '2022-03-10T00:20:57.016Z workers [worker #0, session #xbs0q] Running tests in sandbox\n',
    '2022-03-10T00:20:57.140Z workers Scheduling Jest Test Run (xbs0q): 2022-03-10T00:20:57.017Z\n',
    '2022-03-10T00:20:57.142Z workers [xbs0q] Loaded unknown number of test(s)\n',
    '2022-03-10T00:20:57.142Z workers [xbs0q] Test executed: foo\n',
    '2022-03-10T00:20:57.143Z workers [xbs0q] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:20:57.143Z workers Jest Test Run Complete (xbs0q): 2022-03-10T00:20:57.140Z\n',
    '2022-03-10T00:20:57.144Z workers [xbs0q] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:57.144Z project Test run finished\n',
    '2022-03-10T00:20:57.144Z project Processed console.log entries\n',
    '2022-03-10T00:20:57.144Z project Processed loading sequences\n',
    '2022-03-10T00:20:57.144Z project Processed executed tests\n',
    '2022-03-10T00:20:57.144Z project Processed code coverage\n',
    '2022-03-10T00:20:57.145Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:20:57.145Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:57.146Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:20:57.359Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:20:57.359Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:57.359Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:57.361Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:57.363Z project Test run started; run priority: 2\n',
    '2022-03-10T00:20:57.363Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:20:57.363Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:20:57.363Z nodeRunner Starting sandbox [worker #0, session #7rbvg]\n',
    '2022-03-10T00:20:57.363Z nodeRunner Preparing sandbox [worker #0, session #7rbvg]\n',
    '2022-03-10T00:20:57.363Z nodeRunner Prepared sandbox [worker #0, session #7rbvg]\n',
    '2022-03-10T00:20:57.363Z workers [worker #0, session #7rbvg] Running tests in sandbox\n',
    '2022-03-10T00:20:57.487Z workers Scheduling Jest Test Run (7rbvg): 2022-03-10T00:20:57.364Z\n',
    '2022-03-10T00:20:57.489Z workers [7rbvg] Loaded unknown number of test(s)\n',
    '2022-03-10T00:20:57.490Z workers [7rbvg] Test executed: foo\n',
    '2022-03-10T00:20:57.491Z workers [7rbvg] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:20:57.491Z workers Jest Test Run Complete (7rbvg): 2022-03-10T00:20:57.486Z\n',
    '2022-03-10T00:20:57.492Z workers [7rbvg] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:57.492Z project Test run finished\n',
    '2022-03-10T00:20:57.492Z project Processed console.log entries\n',
    '2022-03-10T00:20:57.492Z project Processed loading sequences\n',
    '2022-03-10T00:20:57.492Z project Processed executed tests\n',
    '2022-03-10T00:20:57.492Z project Processed code coverage\n',
    '2022-03-10T00:20:57.493Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:20:57.493Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:57.493Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:20:57.563Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:20:57.563Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:57.563Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:57.565Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:57.567Z project Test run started; run priority: 2\n',
    '2022-03-10T00:20:57.567Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:20:57.567Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:20:57.567Z nodeRunner Starting sandbox [worker #0, session #3ahp0]\n',
    '2022-03-10T00:20:57.567Z nodeRunner Preparing sandbox [worker #0, session #3ahp0]\n',
    '2022-03-10T00:20:57.567Z nodeRunner Prepared sandbox [worker #0, session #3ahp0]\n',
    '2022-03-10T00:20:57.567Z workers [worker #0, session #3ahp0] Running tests in sandbox\n',
    '2022-03-10T00:20:57.684Z workers Scheduling Jest Test Run (3ahp0): 2022-03-10T00:20:57.568Z\n',
    '2022-03-10T00:20:57.686Z workers [3ahp0] Loaded unknown number of test(s)\n',
    '2022-03-10T00:20:57.687Z workers [3ahp0] Test executed: foo\n',
    '2022-03-10T00:20:57.689Z workers [3ahp0] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:20:57.690Z workers Jest Test Run Complete (3ahp0): 2022-03-10T00:20:57.684Z\n',
    '2022-03-10T00:20:57.691Z workers [3ahp0] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:57.691Z project Test run finished\n',
    '2022-03-10T00:20:57.691Z project Processed console.log entries\n',
    '2022-03-10T00:20:57.691Z project Processed loading sequences\n',
    '2022-03-10T00:20:57.691Z project Processed executed tests\n',
    '2022-03-10T00:20:57.691Z project Processed code coverage\n',
    '2022-03-10T00:20:57.692Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:20:57.692Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:57.692Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:20:57.890Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:20:57.890Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:57.890Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:57.892Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:57.894Z project Test run started; run priority: 2\n',
    '2022-03-10T00:20:57.894Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:20:57.894Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:20:57.894Z nodeRunner Starting sandbox [worker #0, session #qdkz9]\n',
    '2022-03-10T00:20:57.894Z nodeRunner Preparing sandbox [worker #0, session #qdkz9]\n',
    '2022-03-10T00:20:57.894Z nodeRunner Prepared sandbox [worker #0, session #qdkz9]\n',
    '2022-03-10T00:20:57.894Z workers [worker #0, session #qdkz9] Running tests in sandbox\n',
    '2022-03-10T00:20:58.014Z workers Scheduling Jest Test Run (qdkz9): 2022-03-10T00:20:57.895Z\n',
    '2022-03-10T00:20:58.016Z workers [qdkz9] Loaded unknown number of test(s)\n',
    '2022-03-10T00:20:58.016Z workers [qdkz9] Test executed: foo\n',
    '2022-03-10T00:20:58.017Z workers [qdkz9] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:20:58.018Z workers Jest Test Run Complete (qdkz9): 2022-03-10T00:20:58.014Z\n',
    '2022-03-10T00:20:58.018Z workers [qdkz9] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:58.018Z project Test run finished\n',
    '2022-03-10T00:20:58.018Z project Processed console.log entries\n',
    '2022-03-10T00:20:58.018Z project Processed loading sequences\n',
    '2022-03-10T00:20:58.019Z project Processed executed tests\n',
    '2022-03-10T00:20:58.019Z project Processed code coverage\n',
    '2022-03-10T00:20:58.020Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:20:58.020Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:58.020Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:20:58.344Z fs File changed: test/core/sample.test.ts\n',
    '2022-03-10T00:20:58.345Z fs No changes detected for test/core/sample.test.ts\n',
    '2022-03-10T00:20:58.345Z extended-core File was not changed, but file markers may need to be synced\n',
    '2022-03-10T00:20:58.345Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:59.718Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:20:59.718Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:20:59.718Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:59.720Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:20:59.722Z project Test run started; run priority: 2\n',
    '2022-03-10T00:20:59.722Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:20:59.722Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:20:59.722Z nodeRunner Starting sandbox [worker #0, session #acz93]\n',
    '2022-03-10T00:20:59.722Z nodeRunner Preparing sandbox [worker #0, session #acz93]\n',
    '2022-03-10T00:20:59.722Z nodeRunner Prepared sandbox [worker #0, session #acz93]\n',
    '2022-03-10T00:20:59.722Z workers [worker #0, session #acz93] Running tests in sandbox\n',
    '2022-03-10T00:20:59.871Z workers Scheduling Jest Test Run (acz93): 2022-03-10T00:20:59.723Z\n',
    '2022-03-10T00:20:59.874Z workers [acz93] Loaded unknown number of test(s)\n',
    '2022-03-10T00:20:59.874Z workers [acz93] Test executed: foo\n',
    '2022-03-10T00:20:59.876Z workers [acz93] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:20:59.876Z workers Jest Test Run Complete (acz93): 2022-03-10T00:20:59.870Z\n',
    '2022-03-10T00:20:59.877Z workers [acz93] Sandbox is responsive, closing it\n',
    '2022-03-10T00:20:59.877Z project Test run finished\n',
    '2022-03-10T00:20:59.877Z project Processed console.log entries\n',
    '2022-03-10T00:20:59.877Z project Processed loading sequences\n',
    '2022-03-10T00:20:59.878Z project Processed executed tests\n',
    '2022-03-10T00:20:59.878Z project Processed code coverage\n',
    '2022-03-10T00:20:59.880Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:20:59.880Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:20:59.881Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:20:59.990Z fs File changed: test/core/sample.test.ts\n',
    '2022-03-10T00:20:59.994Z fs No changes detected for test/core/sample.test.ts\n',
    '2022-03-10T00:20:59.995Z extended-core File was not changed, but file markers may need to be synced\n',
    '2022-03-10T00:20:59.995Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:00.090Z fs File changed: test/core/sample.test.ts\n',
    '2022-03-10T00:21:00.091Z fs No changes detected for test/core/sample.test.ts\n',
    '2022-03-10T00:21:00.091Z extended-core File was not changed, but file markers may need to be synced\n',
    '2022-03-10T00:21:00.091Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:01.389Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:21:01.390Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:21:01.390Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:01.393Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:01.395Z project Test run started; run priority: 2\n',
    '2022-03-10T00:21:01.395Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:21:01.395Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:21:01.395Z nodeRunner Starting sandbox [worker #0, session #i3vw5]\n',
    '2022-03-10T00:21:01.395Z nodeRunner Preparing sandbox [worker #0, session #i3vw5]\n',
    '2022-03-10T00:21:01.395Z nodeRunner Prepared sandbox [worker #0, session #i3vw5]\n',
    '2022-03-10T00:21:01.395Z workers [worker #0, session #i3vw5] Running tests in sandbox\n',
    '2022-03-10T00:21:01.518Z workers Scheduling Jest Test Run (i3vw5): 2022-03-10T00:21:01.396Z\n',
    '2022-03-10T00:21:01.519Z workers [i3vw5] Loaded unknown number of test(s)\n',
    '2022-03-10T00:21:01.520Z workers [i3vw5] Test executed: foo\n',
    '2022-03-10T00:21:01.523Z workers [i3vw5] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:21:01.523Z workers Jest Test Run Complete (i3vw5): 2022-03-10T00:21:01.517Z\n',
    '2022-03-10T00:21:01.525Z workers [i3vw5] Sandbox is responsive, closing it\n',
    '2022-03-10T00:21:01.525Z project Test run finished\n',
    '2022-03-10T00:21:01.525Z project Processed console.log entries\n',
    '2022-03-10T00:21:01.525Z project Processed loading sequences\n',
    '2022-03-10T00:21:01.525Z project Processed executed tests\n',
    '2022-03-10T00:21:01.525Z project Processed code coverage\n',
    '2022-03-10T00:21:01.526Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:21:01.526Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:01.526Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:21:01.680Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:21:01.681Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:21:01.681Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:01.682Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:01.683Z project Test run started; run priority: 2\n',
    '2022-03-10T00:21:01.683Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:21:01.683Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:21:01.683Z nodeRunner Starting sandbox [worker #0, session #4eb5e]\n',
    '2022-03-10T00:21:01.683Z nodeRunner Preparing sandbox [worker #0, session #4eb5e]\n',
    '2022-03-10T00:21:01.683Z nodeRunner Prepared sandbox [worker #0, session #4eb5e]\n',
    '2022-03-10T00:21:01.683Z workers [worker #0, session #4eb5e] Running tests in sandbox\n',
    '2022-03-10T00:21:01.815Z workers Scheduling Jest Test Run (4eb5e): 2022-03-10T00:21:01.684Z\n',
    '2022-03-10T00:21:01.816Z workers [4eb5e] Loaded unknown number of test(s)\n',
    '2022-03-10T00:21:01.816Z workers [4eb5e] Test executed: foo\n',
    '2022-03-10T00:21:01.818Z workers [4eb5e] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:21:01.818Z workers Jest Test Run Complete (4eb5e): 2022-03-10T00:21:01.814Z\n',
    '2022-03-10T00:21:01.818Z workers [4eb5e] Sandbox is responsive, closing it\n',
    '2022-03-10T00:21:01.818Z project Test run finished\n',
    '2022-03-10T00:21:01.819Z project Processed console.log entries\n',
    '2022-03-10T00:21:01.819Z project Processed loading sequences\n',
    '2022-03-10T00:21:01.819Z project Processed executed tests\n',
    '2022-03-10T00:21:01.819Z project Processed code coverage\n',
    '2022-03-10T00:21:01.820Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:21:01.820Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:01.820Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:21:04.740Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:21:04.740Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:21:04.740Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:04.748Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:04.750Z project Test run started; run priority: 2\n',
    '2022-03-10T00:21:04.750Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:21:04.750Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:21:04.750Z nodeRunner Starting sandbox [worker #0, session #pbpiu]\n',
    '2022-03-10T00:21:04.750Z nodeRunner Preparing sandbox [worker #0, session #pbpiu]\n',
    '2022-03-10T00:21:04.750Z nodeRunner Prepared sandbox [worker #0, session #pbpiu]\n',
    '2022-03-10T00:21:04.750Z workers [worker #0, session #pbpiu] Running tests in sandbox\n',
    '2022-03-10T00:21:04.876Z workers Scheduling Jest Test Run (pbpiu): 2022-03-10T00:21:04.751Z\n',
    '2022-03-10T00:21:04.877Z workers [pbpiu] Loaded unknown number of test(s)\n',
    '2022-03-10T00:21:04.877Z workers [pbpiu] Test executed: foo\n',
    '2022-03-10T00:21:04.879Z workers [pbpiu] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:21:04.879Z workers Jest Test Run Complete (pbpiu): 2022-03-10T00:21:04.875Z\n',
    '2022-03-10T00:21:04.880Z workers [pbpiu] Sandbox is responsive, closing it\n',
    '2022-03-10T00:21:04.880Z project Test run finished\n',
    '2022-03-10T00:21:04.880Z project Processed console.log entries\n',
    '2022-03-10T00:21:04.880Z project Processed loading sequences\n',
    '2022-03-10T00:21:04.880Z project Processed executed tests\n',
    '2022-03-10T00:21:04.880Z project Processed code coverage\n',
    '2022-03-10T00:21:04.881Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:21:04.882Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:04.882Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:21:05.164Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:21:05.165Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:21:05.165Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:05.167Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:05.168Z project Test run started; run priority: 2\n',
    '2022-03-10T00:21:05.168Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:21:05.168Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:21:05.168Z nodeRunner Starting sandbox [worker #0, session #pozr5]\n',
    '2022-03-10T00:21:05.168Z nodeRunner Preparing sandbox [worker #0, session #pozr5]\n',
    '2022-03-10T00:21:05.168Z nodeRunner Prepared sandbox [worker #0, session #pozr5]\n',
    '2022-03-10T00:21:05.168Z workers [worker #0, session #pozr5] Running tests in sandbox\n',
    '2022-03-10T00:21:05.299Z workers Scheduling Jest Test Run (pozr5): 2022-03-10T00:21:05.169Z\n',
    '2022-03-10T00:21:05.300Z workers [pozr5] Loaded unknown number of test(s)\n',
    '2022-03-10T00:21:05.300Z workers [pozr5] Test executed: foo\n',
    '2022-03-10T00:21:05.301Z workers [pozr5] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:21:05.301Z workers Jest Test Run Complete (pozr5): 2022-03-10T00:21:05.298Z\n',
    '2022-03-10T00:21:05.302Z workers [pozr5] Sandbox is responsive, closing it\n',
    '2022-03-10T00:21:05.302Z project Test run finished\n',
    '2022-03-10T00:21:05.302Z project Processed console.log entries\n',
    '2022-03-10T00:21:05.302Z project Processed loading sequences\n',
    '2022-03-10T00:21:05.302Z project Processed executed tests\n',
    '2022-03-10T00:21:05.302Z project Processed code coverage\n',
    '2022-03-10T00:21:05.303Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:21:05.303Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:05.304Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:21:06.861Z fs File changed: test/core/sample.test.ts\n',
    '2022-03-10T00:21:06.861Z fs No changes detected for test/core/sample.test.ts\n',
    '2022-03-10T00:21:06.861Z extended-core File was not changed, but file markers may need to be synced\n',
    '2022-03-10T00:21:06.862Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:09.077Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:21:09.077Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:21:09.077Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:09.079Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:09.080Z project Test run started; run priority: 2\n',
    '2022-03-10T00:21:09.080Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:21:09.081Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:21:09.081Z nodeRunner Starting sandbox [worker #0, session #vcnp8]\n',
    '2022-03-10T00:21:09.081Z nodeRunner Preparing sandbox [worker #0, session #vcnp8]\n',
    '2022-03-10T00:21:09.081Z nodeRunner Prepared sandbox [worker #0, session #vcnp8]\n',
    '2022-03-10T00:21:09.081Z workers [worker #0, session #vcnp8] Running tests in sandbox\n',
    '2022-03-10T00:21:09.200Z workers Scheduling Jest Test Run (vcnp8): 2022-03-10T00:21:09.082Z\n',
    '2022-03-10T00:21:09.203Z workers [vcnp8] Loaded unknown number of test(s)\n',
    '2022-03-10T00:21:09.203Z workers [vcnp8] Test executed: foo\n',
    '2022-03-10T00:21:09.204Z workers [vcnp8] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:21:09.205Z workers Jest Test Run Complete (vcnp8): 2022-03-10T00:21:09.200Z\n',
    '2022-03-10T00:21:09.206Z workers [vcnp8] Sandbox is responsive, closing it\n',
    '2022-03-10T00:21:09.206Z project Test run finished\n',
    '2022-03-10T00:21:09.206Z project Processed console.log entries\n',
    '2022-03-10T00:21:09.206Z project Processed loading sequences\n',
    '2022-03-10T00:21:09.206Z project Processed executed tests\n',
    '2022-03-10T00:21:09.206Z project Processed code coverage\n',
    '2022-03-10T00:21:09.207Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:21:09.207Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:09.207Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:21:09.302Z fs File changed: test/core/sample.test.ts\n',
    '2022-03-10T00:21:09.303Z fs No changes detected for test/core/sample.test.ts\n',
    '2022-03-10T00:21:09.303Z extended-core File was not changed, but file markers may need to be synced\n',
    '2022-03-10T00:21:09.303Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:10.130Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:21:10.131Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:21:10.131Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:10.134Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:10.136Z project Test run started; run priority: 2\n',
    '2022-03-10T00:21:10.136Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:21:10.136Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:21:10.136Z nodeRunner Starting sandbox [worker #0, session #cr1rz]\n',
    '2022-03-10T00:21:10.136Z nodeRunner Preparing sandbox [worker #0, session #cr1rz]\n',
    '2022-03-10T00:21:10.137Z nodeRunner Prepared sandbox [worker #0, session #cr1rz]\n',
    '2022-03-10T00:21:10.137Z workers [worker #0, session #cr1rz] Running tests in sandbox\n',
    '2022-03-10T00:21:10.255Z workers Scheduling Jest Test Run (cr1rz): 2022-03-10T00:21:10.138Z\n',
    '2022-03-10T00:21:10.257Z workers [cr1rz] Loaded unknown number of test(s)\n',
    '2022-03-10T00:21:10.257Z workers [cr1rz] Test executed: foo\n',
    '2022-03-10T00:21:10.259Z workers [cr1rz] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:21:10.259Z workers Jest Test Run Complete (cr1rz): 2022-03-10T00:21:10.255Z\n',
    '2022-03-10T00:21:10.259Z workers [cr1rz] Sandbox is responsive, closing it\n',
    '2022-03-10T00:21:10.260Z project Test run finished\n',
    '2022-03-10T00:21:10.260Z project Processed console.log entries\n',
    '2022-03-10T00:21:10.260Z project Processed loading sequences\n',
    '2022-03-10T00:21:10.260Z project Processed executed tests\n',
    '2022-03-10T00:21:10.260Z project Processed code coverage\n',
    '2022-03-10T00:21:10.261Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:21:10.261Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:10.261Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:21:10.322Z fs File changed in editor: test/core/sample.test.ts\n',
    '2022-03-10T00:21:10.322Z uiService Outgoing message ui:files\n',
    '2022-03-10T00:21:10.322Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:10.324Z uiService Outgoing message ui:busy\n',
    '2022-03-10T00:21:10.326Z project Test run started; run priority: 2\n',
    '2022-03-10T00:21:10.326Z testTask Test files from affected: 1, from deleted or manually requested: 0, from recently changed: 0, from loaded by: 0, from failing: 0\n',
    '2022-03-10T00:21:10.326Z workers Starting test run, priority: 2\n',
    '2022-03-10T00:21:10.326Z nodeRunner Starting sandbox [worker #0, session #ch9jn]\n',
    '2022-03-10T00:21:10.327Z nodeRunner Preparing sandbox [worker #0, session #ch9jn]\n',
    '2022-03-10T00:21:10.327Z nodeRunner Prepared sandbox [worker #0, session #ch9jn]\n',
    '2022-03-10T00:21:10.327Z workers [worker #0, session #ch9jn] Running tests in sandbox\n',
    '2022-03-10T00:21:10.448Z workers Scheduling Jest Test Run (ch9jn): 2022-03-10T00:21:10.328Z\n',
    '2022-03-10T00:21:10.449Z workers [ch9jn] Loaded unknown number of test(s)\n',
    '2022-03-10T00:21:10.449Z workers [ch9jn] Test executed: foo\n',
    '2022-03-10T00:21:10.450Z workers [ch9jn] Run 1 test(s), skipped 0 test(s)\n',
    '2022-03-10T00:21:10.451Z workers Jest Test Run Complete (ch9jn): 2022-03-10T00:21:10.447Z\n',
    '2022-03-10T00:21:10.452Z workers [ch9jn] Sandbox is responsive, closing it\n',
    '2022-03-10T00:21:10.452Z project Test run finished\n',
    '2022-03-10T00:21:10.452Z project Processed console.log entries\n',
    '2022-03-10T00:21:10.452Z project Processed loading sequences\n',
    '2022-03-10T00:21:10.452Z project Processed executed tests\n',
    '2022-03-10T00:21:10.452Z project Processed code coverage\n',
    '2022-03-10T00:21:10.453Z project Test run result processed and sent to IDE\n',
    '2022-03-10T00:21:10.453Z uiService Outgoing message ui:summary\n',
    '2022-03-10T00:21:10.453Z uiService Outgoing message ui:tests:someResultsUpdated\n',
    '2022-03-10T00:21:18.408Z fs No metadata for added file found: .git/info/exclude\n',
    '2022-03-10T00:21:18.510Z fs No metadata for added file found: .git/description\n',
    '2022-03-10T00:21:18.510Z fs File changed: .git/info/exclude\n',
    '2022-03-10T00:21:18.510Z fs No metadata for changed file found: .git/info/exclude\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/commit-msg.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/pre-rebase.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/pre-commit.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/applypatch-msg.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/prepare-commit-msg.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/fsmonitor-watchman.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/pre-receive.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/post-update.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/pre-merge-commit.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/pre-applypatch.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/pre-push.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/update.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/hooks/push-to-checkout.sample\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/HEAD\n',
    '2022-03-10T00:21:18.511Z fs No metadata for added file found: .git/config\n',
    '2022-03-10T00:21:18.511Z fs File changed: .git/config\n',
    '2022-03-10T00:21:18.511Z fs No metadata for changed file found: .git/config\n',
    '2022-03-10T00:21:32.863Z fs No metadata for added file found: .git/index\n',
    '2022-03-10T00:21:44.087Z fs No metadata for added file found: .git/index.lock\n',
    '2022-03-10T00:21:44.189Z fs File deleted: .git/index.lock\n',
    '2022-03-10T00:21:44.189Z fs No metadata for deleted file found: .git/index.lock\n',
    '2022-03-10T00:21:44.189Z fs File changed: .git/index\n',
    '2022-03-10T00:21:44.189Z fs No metadata for changed file found: .git/index\n',
    '2022-03-10T00:21:44.189Z fs No metadata for added file found: .git/COMMIT_EDITMSG\n',
    '2022-03-10T00:21:44.190Z fs No metadata for added file found: .git/logs/HEAD\n',
    '2022-03-10T00:21:44.190Z fs No metadata for added file found: .git/logs/refs/heads/master\n',
    '2022-03-10T00:21:44.190Z fs No metadata for added file found: .git/refs/heads/master\n',
    '2022-03-10T00:21:51.043Z fs File changed: .git/config\n',
    '2022-03-10T00:21:51.043Z fs No metadata for changed file found: .git/config\n',
    '2022-03-10T00:25:35.294Z fs File changed: .git/config\n',
    '2022-03-10T00:25:35.294Z fs No metadata for changed file found: .git/config\n',
    '2022-03-10T00:25:35.294Z fs No metadata for added file found: .git/logs/refs/remotes/origin/master\n',
    '2022-03-10T00:25:35.294Z fs No metadata for added file found: .git/refs/remotes/origin/master\n'
  ]
}
@smcenlly smcenlly transferred this issue from wallabyjs/public Mar 10, 2022
@smcenlly smcenlly transferred this issue from wallabyjs/quokka Mar 10, 2022
@smcenlly
Copy link
Member

Sorry for transfer confusion... description said Quokka - had thought this was in the wrong repo. Is actually Wallaby

@abirtley
Copy link
Author

Sorry for transfer confusion... description said Quokka - had thought this was in the wrong repo. Is actually Wallaby

🤦 my bad sorry!

@smcenlly
Copy link
Member

We're not exactly sure of the cause yet, but the issue seems to be related to esbuild and not Wallaby.

We patched node_modules/esbuild-runner/jest.js with the following code:

"use strict";
Object.defineProperty(exports, "__esModule", { value: true });
var esbuild_1 = require("./esbuild");
require("./register");
function process(src, filename) {
    console.log('*****************************');
    console.log('esbuild-input:src', src);
    console.log('*****************************');
    console.log('esbuild-input:filename', filename);
    const result = (0, esbuild_1.transpile)(src, filename, { type: "transform" });
    console.log('*****************************');
    console.log('esbuild-output', result);
    console.log('*****************************');
    return result;
}
exports.default = { process: process };

And we can see that the correct inputs are being provided to esbuild, but it's returning the wrong output:

console.log: *****************************
​[Info]​ console.log: esbuild-input:src /* eslint-disable fp/no-nil, fp/no-unused-expression */
​[Info]​ import { Sample } from '../../core/sample';
​[Info]​ 
​[Info]​ it('foo', () => {
​[Info]​   Sample(); //?
​[Info]​   
​[Info]​   expect(Sample()).toEqual('The API is live');  
​[Info]​ });
​[Info]​ console.log: *****************************
​[Info]​ console.log: esbuild-input:filename /repos/temp/quokka-slow-typescript-reproduction/test/core/sample.test.ts
​[Info]​ console.log: *****************************
​[Info]​ console.log: esbuild-output var __create = Object.create;
​[Info]​ var __defProp = Object.defineProperty;
​[Info]​ var __getOwnPropDesc = Object.getOwnPropertyDescriptor;
​[Info]​ var __getOwnPropNames = Object.getOwnPropertyNames;
​[Info]​ var __getProtoOf = Object.getPrototypeOf;
​[Info]​ var __hasOwnProp = Object.prototype.hasOwnProperty;
​[Info]​ var __markAsModule = (target) => __defProp(target, "__esModule", { value: true });
​[Info]​ var __reExport = (target, module2, desc) => {
​[Info]​   if (module2 && typeof module2 === "object" || typeof module2 === "function") {
​[Info]​     for (let key of __getOwnPropNames(module2))
​[Info]​       if (!__hasOwnProp.call(target, key) && key !== "default")
​[Info]​         __defProp(target, key, { get: () => module2[key], enumerable: !(desc = __getOwnPropDesc(module2, key)) || desc.enumerable });
​[Info]​   }
​[Info]​   return target;
​[Info]​ };
​[Info]​ var __toModule = (module2) => {
​[Info]​   return __reExport(__markAsModule(__defProp(module2 != null ? __create(__getProtoOf(module2)) : {}, "default", module2 && module2.__esModule && "default" in module2 ? { get: () => module2.default, enumerable: true } : { value: module2, enumerable: true })), module2);
​[Info]​ };
​[Info]​ var import_sample = __toModule(require("../../core/sample"));
​[Info]​ it("foo", () => {
​[Info]​   (0, import_sample.Sample)();
​[Info]​   expect((0, import_sample.Sample)()).toEqual("The API is notlive");
​[Info]​ });
​[Info]​ //# sourceMappingURL=data:application/json;base64,ewogICJ2ZXJzaW9uIjogMywKICAic291cmNlcyI6IFsiL1VzZXJzL3NtY2VubGx5L3JlcG9zL3RlbXAvcXVva2thLXNsb3ctdHlwZXNjcmlwdC1yZXByb2R1Y3Rpb24vdGVzdC9jb3JlL3NhbXBsZS50ZXN0LnRzIl0sCiAgInNvdXJjZXNDb250ZW50IjogWyIvKiBlc2xpbnQtZGlzYWJsZSBmcC9uby1uaWwsIGZwL25vLXVudXNlZC1leHByZXNzaW9uICovXHJcbmltcG9ydCB7IFNhbXBsZSB9IGZyb20gJy4uLy4uL2NvcmUvc2FtcGxlJztcclxuXHJcbml0KCdmb28nLCAoKSA9PiB7XHJcbiAgU2FtcGxlKCk7IC8vP1xyXG4gIFxyXG4gIGV4cGVjdChTYW1wbGUoKSkudG9FcXVhbCgnVGhlIEFQSSBpcyBub3RsaXZlJyk7ICBcclxufSk7XHJcbiJdLAogICJtYXBwaW5ncyI6ICI7Ozs7Ozs7Ozs7Ozs7Ozs7OztBQUNBLG9CQUF1QjtBQUV2QixHQUFHLE9BQU8sTUFBTTtBQUNkO0FBRUEsU0FBTyw2QkFBVSxRQUFRO0FBQUE7IiwKICAibmFtZXMiOiBbXQp9Cg==
​[Info]​ console.log: *****************************

We'll keep investigating to see if we can work out why esbuild is returning the wrong value.

@smcenlly
Copy link
Member

We found that esbuild-runner/jest has its own internal cache of transforms (https://github.com/folke/esbuild-runner/blob/main/src/cache.ts) and does not consider the content being transformed, only the file stamp of the file being transformed. In Wallaby's case, the file has not been flushed to disk and so the cached value is being returned. This caching mechanism may also be unnecessary as jest has its own caching mechanism that it will be using if the file contents are not changed.

We have had some other customers successfully use esbuild-jest instead of what you are using, esbuild-runner. esbuild-jest seems to be a little more popular (~4.5x more weekly downloads).

I'll raise an issue in esbuild-runner repo and describe the issue so they can consider fixing it.

@smcenlly
Copy link
Member

We've created a pull request that should fix the issue. folke/esbuild-runner#51

Since the issue isn't related to Wallaby and there are potential workarounds (e.g. use a different esbuild-jest transformer) I believe we can close this issue.

If you're still having problems, let us know and we can reopen it.

@abirtley
Copy link
Author

Thank you @smcenlly , you have been incredibly responsive and helpful.

Switching to esbuild-jest instead of esbuild-runner did indeed solve the issue. For anyone who stumbles upon this and is interested in how to do it (it's not hard) you can see the relevant changes here: abirtley/quokka-slow-typescript-reproduction@e3edb69.

(Of course, it's possible that your pull request in esbuild-runner will be accepted before anyone else encounters this problem.)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants