Merge branch 'fixMoreShellErrors' into issue9186

* fixMoreShellErrors: Misc Misc Misc Misc Fixes Added logging More logging Misc Misc Fix tests
microsoft · Mar 15, 2022 · 802c605 · 802c605
2 parents 6f222fa + 48b7926
commit 802c605
Show file tree

Hide file tree

Showing 5 changed files with 46 additions and 20 deletions.
diff --git a/src/notebooks/execution/cellExecution.ts b/src/notebooks/execution/cellExecution.ts
@@ -634,6 +634,7 @@ export class CellExecution implements IDisposable {
         // In such circumstances, create a temporary task & use that to update the output (only cell execution tasks can update cell output).
         const task = this.execution || this.createTemporaryTask();
         this.clearLastUsedStreamOutput();
+        traceCellMessage(this.cell, 'Append output in addToCellData');
         task?.appendOutput([cellOutput]).then(noop, noop);
         this.endTemporaryTask();
     }
@@ -755,6 +756,7 @@ export class CellExecution implements IDisposable {
         // Clear output if waiting for a clear
         const clearOutput = clearState.value;
         if (clearOutput) {
+            traceCellMessage(this.cell, 'Clear cell output');
             this.clearLastUsedStreamOutput();
             task?.clearOutput().then(noop, noop);
             clearState.update(false);
@@ -789,6 +791,7 @@ export class CellExecution implements IDisposable {
                 name: msg.content.name,
                 text: this.lastUsedStreamOutput.text
             });
+            traceCellMessage(this.cell, `Replace output items ${this.lastUsedStreamOutput.text.substring(0, 100)}`);
             task?.replaceOutputItems(output.items, this.lastUsedStreamOutput.output).then(noop, noop);
         } else if (clearOutput) {
             // Replace the current outputs with a single new output.
@@ -799,6 +802,7 @@ export class CellExecution implements IDisposable {
                 text
             });
             this.lastUsedStreamOutput = { output, stream: msg.content.name, text };
+            traceCellMessage(this.cell, `Replace output ${this.lastUsedStreamOutput.text.substring(0, 100)}`);
             task?.replaceOutput([output]).then(noop, noop);
         } else {
             // Create a new output
@@ -809,6 +813,7 @@ export class CellExecution implements IDisposable {
                 text
             });
             this.lastUsedStreamOutput = { output, stream: msg.content.name, text };
+            traceCellMessage(this.cell, `Append output ${this.lastUsedStreamOutput.text.substring(0, 100)}`);
             task?.appendOutput([output]).then(noop, noop);
         }
         this.endTemporaryTask();
@@ -909,6 +914,7 @@ export class CellExecution implements IDisposable {
         // This message could have come from a background thread.
         // In such circumstances, create a temporary task & use that to update the output (only cell execution tasks can update cell output).
         const task = this.execution || this.createTemporaryTask();
+        traceCellMessage(this.cell, `Replace output items in display data ${newOutput.items.length}`);
         task?.replaceOutputItems(newOutput.items, outputToBeUpdated).then(noop, noop);
         this.endTemporaryTask();
     }

diff --git a/src/test/datascience/jupyter/kernels/installationPrompts.vscode.test.ts b/src/test/datascience/jupyter/kernels/installationPrompts.vscode.test.ts
@@ -49,7 +49,8 @@ import {
     waitForKernelToChange,
     insertCodeCell,
     waitForExecutionCompletedSuccessfully,
-    getCellOutputs
+    getCellOutputs,
+    waitForCellHavingOutput
 } from '../../notebook/helper';
 import * as kernelSelector from '../../../../notebooks/controllers/kernelSelector';
 
@@ -568,7 +569,7 @@ suite('DataScience Install IPyKernel (slow) (install)', function () {
                     ? Promise.resolve()
                     : waitForIPyKernelToGetInstalled(),
                 waitForExecutionCompletedSuccessfully(cell),
-                waitForCondition(async () => cell.outputs.length > 0, defaultNotebookTestTimeout, 'No cell output')
+                waitForCellHavingOutput(cell)
             ]);
 
             console.log('Stepd');

diff --git a/src/test/datascience/notebook/executionService.vscode.test.ts b/src/test/datascience/notebook/executionService.vscode.test.ts
@@ -419,29 +419,55 @@ suite('DataScience - VSCode Notebook - (Execution) (slow)', function () {
 
         await Promise.all([
             runAllCellsInActiveNotebook(),
-            waitForCellExecutionToComplete(cell3),
-            waitForCellHavingOutput(cell3)
+            waitForCellExecutionToComplete(cell1),
+            waitForCondition(
+                async () => {
+                    // Sometimes the cell can fail execution (IPython can sometimes throw an error).
+                    const output = getCellOutputs(cell1).trim();
+                    if (output !== '<No cell outputs>' && output.length > 0) {
+                        return true;
+                    }
+                    if (hasErrorOutput(cell1.outputs)) {
+                        return true;
+                    }
+                    return false;
+                },
+                defaultNotebookTestTimeout,
+                'Cell did not have output'
+            )
         ]);
 
         // On windows `!where python`, prints multiple items in the output (all executables found).
-        const shellExecutable = getCellOutputs(cell1).trim().split('\n')[0].trim();
-        const sysExecutable = getCellOutputs(cell3).trim();
+        const cell1Output = getCellOutputs(cell1);
+        const shellExecutable = cell1Output
+            .split('\n')
+            .filter((item) => item.length)[0]
+            .trim();
 
         // Sometimes the IPython can (sometimes) fail with an error of `shell not found`.
         // For now, we'll ignore these errors
         // We already have tests that ensures the first path in sys.path points to where the executable is located.
         // Hence skipping this test in such cases is acceptable.
-        if (hasErrorOutput(cell3.outputs)) {
-            const errorOutput = translateCellErrorOutput(cell3.outputs[0]);
-            if (errorOutput.traceback.includes('shell not found') || errorOutput.evalue.includes('shell not found')) {
+        let errorOutput = '';
+        if (hasErrorOutput(cell1.outputs)) {
+            const error = translateCellErrorOutput(cell1.outputs[0]);
+            errorOutput = `${error.evalue}:${error.traceback}`;
+            if (errorOutput.includes('shell not found')) {
                 return this.skip();
             }
         }
+        await Promise.all([waitForCellExecutionToComplete(cell3), waitForCellHavingOutput(cell3)]);
+
+        const sysExecutable = getCellOutputs(cell3).trim();
 
         // First path in PATH must be the directory where executable is located.
         assert.ok(
             areInterpreterPathsSame(shellExecutable.toLowerCase(), sysExecutable.toLowerCase()),
-            `Python paths do not match ${shellExecutable}, ${sysExecutable}`
+            `Python paths do not match ${shellExecutable}, ${sysExecutable}. Output is (${cell1Output}, ${
+                cell1.outputs.length
+            }) (${cell1.outputs
+                .map((item) => item.items.map((i) => i.mime).join(','))
+                .join('#')}), error is ${errorOutput}`
         );
     });
     test('Testing streamed output', async () => {

diff --git a/src/test/datascience/notebook/helper.ts b/src/test/datascience/notebook/helper.ts
@@ -560,7 +560,7 @@ export async function waitForCellHavingOutput(cell: NotebookCell) {
     return waitForCondition(
         async () => {
             const cellOutputs = getCellOutputs(cell);
-            return cellOutputs.length > 0 && !cellOutputs[0].includes('No cell outputs');
+            return cellOutputs.length > 0 && !cellOutputs.includes('No cell outputs');
         },
         defaultNotebookTestTimeout,
         'No output'
@@ -753,13 +753,6 @@ export async function waitForTextOutput(
             }, it is ${getCellOutputs(cell)}`
     );
 }
-export async function waitForCellToHaveOutput(cell: NotebookCell, timeout = defaultNotebookTestTimeout) {
-    await waitForCondition(
-        async () => cell.outputs.length > 0,
-        timeout,
-        () => `No outputs for Cell ${cell.index + 1}`
-    );
-}
 export function assertNotHasTextOutputInVSCode(cell: NotebookCell, text: string, index: number, isExactMatch = true) {
     const cellOutputs = cell.outputs;
     assert.ok(cellOutputs, 'No output');

diff --git a/src/test/datascience/notebook/kernelSysPath.vscode.test.ts b/src/test/datascience/notebook/kernelSysPath.vscode.test.ts
@@ -23,7 +23,7 @@ import {
     startJupyterServer,
     waitForExecutionCompletedSuccessfully,
     waitForKernelToChange,
-    waitForCellToHaveOutput
+    waitForCellHavingOutput
 } from './helper';
 import { traceInfoIfCI } from '../../../client/common/logger';
 
@@ -103,7 +103,7 @@ suite('sys.path in Python Kernels', function () {
         await Promise.all([
             runAllCellsInActiveNotebook(),
             waitForExecutionCompletedSuccessfully(cell),
-            waitForCellToHaveOutput(cell)
+            waitForCellHavingOutput(cell)
         ]);
 
         const output = Buffer.from(cell.outputs[0].items[0].data).toString().trim();