Splitting test log

Rich Chiodo (rchiodo) · Oct 10, 2020 · Oct 7, 2020 · Oct 8, 2020 · Oct 8, 2020 · Oct 8, 2020
commit 2aac1502eac537b5076f154f04d1e55caa448e03
diff --git a/.github/workflows/pr_datascience.yml b/.github/workflows/pr_datascience.yml
@@ -1,9 +1,6 @@
 name: Pull Request DataScience
 
 on:
-  push: 
-    branches: 
-      - main
   pull_request:
     branches:
       - main

diff --git a/.vscode/settings.json b/.vscode/settings.json
@@ -45,7 +45,7 @@
         "source.fixAll.eslint": true,
         "source.fixAll.tslint": true
     },
-    "python.languageServer": "Microsoft",
+    "python.languageServer": "Pylance",
     "python.analysis.logLevel": "Trace",
     "python.analysis.downloadChannel": "beta",
     "python.linting.pylintEnabled": false,

diff --git a/ThirdPartyNotices-Repository.txt b/ThirdPartyNotices-Repository.txt
@@ -20,6 +20,7 @@ Microsoft Python extension for Visual Studio Code incorporates third party mater
 16. ipywidgets (https://github.com/jupyter-widgets)
 17. vscode-cpptools (https://github.com/microsoft/vscode-cpptools)
 18. font-awesome (https://github.com/FortAwesome/Font-Awesome)
+19. mocha (https://github.com/mochajs/mocha)
 
 %%
 Go for Visual Studio Code NOTICES, INFORMATION, AND LICENSE BEGIN HERE
@@ -1195,4 +1196,33 @@ LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
 OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
 SOFTWARE.
 =========================================
-END OF jedi-language-server NOTICES, INFORMATION, AND LICENSE
+END OF jedi-language-server NOTICES, INFORMATION, AND LICENSE
+
+%% mocha NOTICES, INFORMATION, AND LICENSE BEGIN HERE
+=========================================
+
+(The MIT License)
+
+Copyright (c) 2011-2020 OpenJS Foundation and contributors, https://openjsf.org
+
+Permission is hereby granted, free of charge, to any person obtaining
+a copy of this software and associated documentation files (the
+'Software'), to deal in the Software without restriction, including
+without limitation the rights to use, copy, modify, merge, publish,
+distribute, sublicense, and/or sell copies of the Software, and to
+permit persons to whom the Software is furnished to do so, subject to
+the following conditions:
+
+The above copyright notice and this permission notice shall be
+included in all copies or substantial portions of the Software.
+
+THE SOFTWARE IS PROVIDED 'AS IS', WITHOUT WARRANTY OF ANY KIND,
+EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
+MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT.
+IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY
+CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT,
+TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE
+SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
+
+=========================================
+END OF mocha NOTICES, INFORMATION, AND LICENSE
diff --git a/build/.mocha-multi-reporters.config b/build/.mocha-multi-reporters.config
@@ -1,3 +1,3 @@
 {
-    "reporterEnabled": "spec,mocha-junit-reporter"
+    "reporterEnabled": "./build/ci/scripts/spec_with_pid,mocha-junit-reporter"
 }
diff --git a/build/ci/scripts/spec_with_pid.js b/build/ci/scripts/spec_with_pid.js
@@ -0,0 +1,96 @@
+'use strict';
+/**
+ * @module Spec
+ */
+/**
+ * Module dependencies.
+ */
+
+var Base = require('mocha/lib/reporters/base');
+var constants = require('mocha/lib/runner').constants;
+var EVENT_RUN_BEGIN = constants.EVENT_RUN_BEGIN;
+var EVENT_RUN_END = constants.EVENT_RUN_END;
+var EVENT_SUITE_BEGIN = constants.EVENT_SUITE_BEGIN;
+var EVENT_SUITE_END = constants.EVENT_SUITE_END;
+var EVENT_TEST_FAIL = constants.EVENT_TEST_FAIL;
+var EVENT_TEST_PASS = constants.EVENT_TEST_PASS;
+var EVENT_TEST_PENDING = constants.EVENT_TEST_PENDING;
+var inherits = require('mocha/lib/utils').inherits;
+var color = Base.color;
+
+/**
+ * Expose `Spec`.
+ */
+
+exports = module.exports = Spec;
+
+/**
+ * Constructs a new `Spec` reporter instance.
+ *
+ * @public
+ * @class
+ * @memberof Mocha.reporters
+ * @extends Mocha.reporters.Base
+ * @param {Runner} runner - Instance triggers reporter actions.
+ * @param {Object} [options] - runner options
+ */
+function Spec(runner, options) {
+    Base.call(this, runner, options);
+
+    var self = this;
+    var indents = 0;
+    var n = 0;
+
+    function indent() {
+        return Array(indents).join('  ');
+    }
+
+    runner.on(EVENT_RUN_BEGIN, function () {
+        Base.consoleLog();
+    });
+
+    runner.on(EVENT_SUITE_BEGIN, function (suite) {
+        ++indents;
+        Base.consoleLog(color('suite', `${process.pid} %s%s`), indent(), suite.title);
+    });
+
+    runner.on(EVENT_SUITE_END, function () {
+        --indents;
+        if (indents === 1) {
+            Base.consoleLog();
+        }
+    });
+
+    runner.on(EVENT_TEST_PENDING, function (test) {
+        var fmt = indent() + color('pending', `${process.pid}   - %s`);
+        Base.consoleLog(fmt, test.title);
+    });
+
+    runner.on(EVENT_TEST_PASS, function (test) {
+        var fmt;
+        if (test.speed === 'fast') {
+            fmt = indent() + color('checkmark', `${process.pid}   ` + Base.symbols.ok) + color('pass', ' %s');
+            Base.consoleLog(fmt, test.title);
+        } else {
+            fmt =
+                indent() +
+                color('checkmark', `${process.pid}   ` + Base.symbols.ok) +
+                color('pass', ' %s') +
+                color(test.speed, ' (%dms)');
+            Base.consoleLog(fmt, test.title, test.duration);
+        }
+    });
+
+    runner.on(EVENT_TEST_FAIL, function (test) {
+        Base.consoleLog(indent() + color('fail', `${process.pid}  %d) %s`), ++n, test.title);
+    });
+
+    runner.once(EVENT_RUN_END, self.epilogue.bind(self));
+}
+
+/**
+ * Inherit from `Base.prototype`.
+ */
+inherits(Spec, Base);
+
+Spec.description = 'hierarchical & verbose [default]';
diff --git a/pythonFiles/vscode_datascience_helpers/tests/logParser.py b/pythonFiles/vscode_datascience_helpers/tests/logParser.py
@@ -0,0 +1,81 @@
+import sys
+import argparse
+import os
+os.system("color")
+from pathlib import Path
+import re
+
+parser = argparse.ArgumentParser(description='Parse a test log into its parts')
+parser.add_argument('testlog', type=str, nargs=1, help='Log to parse')
+parser.add_argument('--testoutput', action='store_true', help='Show all failures and passes')
+parser.add_argument('--split', action='store_true', help='Split into per process files. Each file will have the pid appended')
+ansi_escape = re.compile(r'\x1B(?:[@-Z\\-_]|\[[0-?]*[ -/]*[@-~])')
+pid_regex = re.compile(r'(\d+).*')
+
+def isUnwantedOutput(s: str):
+    return s.startswith("{\"json") or s.startswith("Content-type") or s.startswith("Content-Type") or s.startswith("Output") or s.startswith("Starting") or s.startswith("Kernel")
+
+def printTestOutput(testlog):
+    # Find all the lines that don't have a PID in them. These are the test output
+    p = Path(testlog[0])
+    with p.open() as f:
+        for line in f.readlines():
+            stripped = line.strip()
+            if (not isUnwantedOutput(stripped) and len(stripped) > 0):
+                if (stripped[0] < '0'):
+                    print(line.rstrip()) # Should be a test line
+                elif (stripped[0] > '9'):
+                    print(line.rstrip()) # Not starting with a number
+
+def splitByPid(testlog):
+    # Split testlog into prefixed logs based on pid
+    baseFile = os.path.splitext(testlog[0])[0]
+    p = Path(testlog[0])
+    pids = set()
+    logs = {}
+    pid = None
+    with p.open() as f:
+        for line in f.readlines():
+            stripped = ansi_escape.sub('', line.strip())
+            # See if starts with a pid
+            if (len(stripped) > 0 and stripped[0] <= '9' and stripped[0] >= '0'):
+                # Pull out the pid
+                match = pid_regex.match(stripped)
+
+                # Pids are at least two digits
+                if (match != None and len(match.group(1)) > 2):
+                    # Pid is found
+                    pid = int(match.group(1))
+
+                    # See if we've created a log for this pid or not
+                    if (not pid in pids):
+                        pids.add(pid)
+                        logFile = '{}_{}.log'.format(baseFile, pid)
+                        print('Writing to new log: ' + logFile)
+                        logs[pid] = Path(logFile).open(mode="w")
+
+                # Add this line to the log
+                if (pid != None):
+                    logs[pid].write(line)
+    # Close all of the open logs
+    for key in logs:
+        logs[key].close()
+
+
+
+
+def doWork(args):
+    if (not args.testlog):
+        print('Test log should be passed')
+    elif (args.testoutput):
+        printTestOutput(args.testlog)
+    elif (args.split):
+        splitByPid(args.testlog)
+    else:
+        parser.print_usage()
+
+def main():
+    doWork(parser.parse_args())
+
+if __name__ == "__main__":
+    main()
diff --git a/src/client/common/process/baseDaemon.ts b/src/client/common/process/baseDaemon.ts
@@ -177,14 +177,20 @@ export abstract class BasePythonDaemon {
         return Object.keys(options).every((item) => daemonSupportedSpawnOptions.indexOf(item as any) >= 0);
     }
     protected sendRequestWithoutArgs<R, E, RO>(type: RequestType0<R, E, RO>): Thenable<R> {
-        return Promise.race([this.connection.sendRequest(type), this.connectionClosedDeferred.promise]);
+        if (this.proc && this.proc.exitCode === null) {
+            return Promise.race([this.connection.sendRequest(type), this.connectionClosedDeferred.promise]);
+        }
+        return this.connectionClosedDeferred.promise;
     }
     protected sendRequest<P, R, E, RO>(type: RequestType<P, R, E, RO>, params?: P): Thenable<R> {
-        if (!this.isAlive) {
+        if (!this.isAlive || this.proc.exitCode !== null) {
             traceError('Daemon is handling a request after death.');
         }
-        // Throw an error if the connection has been closed.
-        return Promise.race([this.connection.sendRequest(type, params), this.connectionClosedDeferred.promise]);
+        if (this.proc && this.proc.exitCode === null) {
+            // Throw an error if the connection has been closed.
+            return Promise.race([this.connection.sendRequest(type, params), this.connectionClosedDeferred.promise]);
+        }
+        return this.connectionClosedDeferred.promise;
     }
     protected throwIfRPCConnectionIsDead() {
         if (!this.isAlive) {

diff --git a/src/client/logging/formatters.ts b/src/client/logging/formatters.ts
@@ -37,13 +37,13 @@ function normalizeLevel(name: LogLevelName): string {
 // Return a log entry that can be emitted as-is.
 function formatMessage(level: LogLevelName, timestamp: string, message: string): string {
     const levelFormatted = normalizeLevel(level);
-    return `${levelFormatted} ${timestamp}: ${message}`;
+    return `${process.pid} ${levelFormatted} ${timestamp}: ${message}`;
 }
 
 // Return a log entry that can be emitted as-is.
 function formatLabeledMessage(level: LogLevelName, timestamp: string, label: string, message: string): string {
     const levelFormatted = normalizeLevel(level);
-    return `${levelFormatted} ${label} ${timestamp}: ${message}`;
+    return `${process.pid} ${levelFormatted} ${label} ${timestamp}: ${message}`;
 }
 
 // Return a minimal format object that can be used with a "winston"

diff --git a/src/test/datascience/uiTests/ipywidget.ui.functional.test.ts b/src/test/datascience/uiTests/ipywidget.ui.functional.test.ts
@@ -41,7 +41,7 @@ use(chaiAsPromised);
         suiteSetup(function () {
             // Skip all tests until flakiness can be resolved.
             // See issue: https://github.com/microsoft/vscode-python/issues/13936
-            if (IS_CI_SERVER) {
+            if (IS_CI_SERVER || process.env.VSC_PYTHON_FORCE_LOGGING) {
                 this.skip();
             }