Linux/Ubuntu - Issue Triage

[WernerMairl]

Hi
Preface:
I'm a old Windows/Dotnet/Powershell Developer now working on Linux by using all that core xplat technologies (VS-Code, Powershell-Core, dotnet-core).
Working with VS-Code and Powershell on Ubuntu it seems that this technology stack is not used by a lot of people. I have a lot of problems but i see no existing issues about this inside the GitHub Repositories.
I hope we can push the quality a litle bit.....

working on the investigations for the following Issue with VS-Code and Powershell
PowerShell/vscode-powershell#824
i see different problems inside the EditorServices (log)

Please help me to sort that out into single issues or point to the known issues somewhere else.

My Session Log File (using Ubuntu Desktop 16.04 LTS fresh installed + current Releases of VS-Code and PS-Plugin) show the following items after the start.
lot of noise but i think the exception should be solved:

1. NullReferenceException inside PowerShellVersionDetails.GetVersionDetails

10/19/17 6:34:40 AM [NORMAL] - Method "StartLogging" at line 144 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Host\EditorServicesHost.cs

    PowerShell Editor Services Host v1.4.1.0 starting (pid 45601)...
    
      Host application details:
    
        Name:      Visual Studio Code Host
        ProfileId: Microsoft.VSCode
        Version:   1.4.3
    

10/19/17 6:34:40 AM [NORMAL] - Method "StartLanguageService" at line 180 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Host\EditorServicesHost.cs

    Language service started, listening on port 22548

10/19/17 6:34:40 AM [NORMAL] - Method "StartDebugService" at line 254 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Host\EditorServicesHost.cs

    Debug service started, listening on port 17180

10/19/17 6:34:41 AM [WARNING] - Method "GetVersionDetails" at line 153 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Session\PowerShellVersionDetails.cs

    Failed to look up PowerShell version, defaulting to version 5.
    
    System.NullReferenceException: Object reference not set to an instance of an object.
       at Microsoft.PowerShell.EditorServices.PowerShellContext.<>c__56`1.<ExecuteScriptAndGetItem>b__56_0(PSObject pso)
       at System.Linq.Enumerable.SelectIListIterator`2.MoveNext()
       at System.Linq.Enumerable.<OfTypeIterator>d__32`1.MoveNext()
       at System.Linq.Enumerable.TryGetFirst[TSource](IEnumerable`1 source, Boolean& found)
       at System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable`1 source)
       at Microsoft.PowerShell.EditorServices.PowerShellContext.ExecuteScriptAndGetItem[TResult](String scriptToExecute, Runspace runspace, TResult defaultValue)
       at Microsoft.PowerShell.EditorServices.Session.PowerShellVersionDetails.GetVersionDetails(Runspace runspace, ILogger logger)

.
2. CmdletInvocationException about "Drive C" - sure drive C does not make sense on Linux

10/19/17 6:34:41 AM [VERBOSE] - Method "SetExecutionPolicy" at line 1443 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Session\PowerShellContext.cs

    Current execution policy: ExecutionPolicy.Unrestricted

10/19/17 6:34:41 AM [ERROR] - Method "CheckForCapability" at line 107 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Session\Capabilities\DscBreakpointCapability.cs

    Could not load the DSC module!
    
    System.Management.Automation.CmdletInvocationException: Cannot find drive. A drive with the name 'C' does not exist. ---> System.Management.Automation.DriveNotFoundException: Cannot find drive. A drive with the name 'C' does not exist.
       at System.Management.Automation.SessionStateInternal.GetDrive(String name, Boolean automount)
       at System.Management.Automation.SessionStateInternal.AutomountBuiltInDrive(String name)
       at System.Management.Automation.SessionStateInternal.GetDrive(String name, Boolean automount)
       at System.Management.Automation.SessionStateInternal.GetDrive(String name)
       at System.Management.Automation.DriveManagementIntrinsics.Get(String driveName)
       at System.Management.Automation.LocationGlobber.GetDriveRootRelativePathFromPSPath(String path, CmdletProviderContext context, Boolean escapeCurrentLocation, PSDriveInfo& workingDriveForPath, CmdletProvider& providerInstance)
       at System.Management.Automation.LocationGlobber.GetProviderPath(String path, CmdletProviderContext context, Boolean isTrusted, ProviderInfo& provider, PSDriveInfo& drive)
       at System.Management.Automation.LocationGlobber.GetProviderPath(String path, CmdletProviderContext context, ProviderInfo& provider, PSDriveInfo& drive)
       at System.Management.Automation.LocationGlobber.GetGlobbedProviderPathsFromMonadPath(String path, Boolean allowNonexistingPaths, CmdletProviderContext context, ProviderInfo& provider, CmdletProvider& providerInstance)
       at System.Management.Automation.LocationGlobber.GetGlobbedProviderPathsFromMonadPath(String path, Boolean allowNonexistingPaths, ProviderInfo& provider, CmdletProvider& providerInstance)
       at System.Management.Automation.PathIntrinsics.GetResolvedProviderPathFromPSPath(String path, ProviderInfo& provider)
       at Microsoft.PowerShell.Commands.ModuleCmdletBase.ResolveRootedFilePath(String filePath, ExecutionContext context)
       at Microsoft.PowerShell.Commands.ImportModuleCommand.ImportModule_LocallyViaName(ImportModuleOptions importModuleOptions, String name)
       at Microsoft.PowerShell.Commands.ImportModuleCommand.ProcessRecord()
       at System.Management.Automation.Cmdlet.DoProcessRecord()
       at System.Management.Automation.CommandProcessor.ProcessRecord()
       --- End of inner exception stack trace ---
       at System.Management.Automation.Runspaces.PipelineBase.Invoke(IEnumerable input)
       at System.Management.Automation.Runspaces.Pipeline.Invoke()
       at System.Management.Automation.PowerShell.Worker.ConstructPipelineAndDoWork(Runspace rs, Boolean performSyncInvoke)
       at System.Management.Automation.PowerShell.Worker.CreateRunspaceIfNeededAndDoWork(Runspace rsToUse, Boolean isSync)
       at System.Management.Automation.PowerShell.CoreInvokeHelper[TInput,TOutput](PSDataCollection`1 input, PSDataCollection`1 output, PSInvocationSettings settings)
       at System.Management.Automation.PowerShell.CoreInvoke[TInput,TOutput](PSDataCollection`1 input, PSDataCollection`1 output, PSInvocationSettings settings)
       at System.Management.Automation.PowerShell.CoreInvoke[TOutput](IEnumerable input, PSDataCollection`1 output, PSInvocationSettings settings)
       at System.Management.Automation.PowerShell.Invoke(IEnumerable input, PSInvocationSettings settings)
       at System.Management.Automation.PowerShell.Invoke()
       at Microsoft.PowerShell.EditorServices.Session.Capabilities.DscBreakpointCapability.CheckForCapability(RunspaceDetails runspaceDetails, PowerShellContext powerShellContext, ILogger logger)

10/19/17 6:34:41 AM [VERBOSE] - Method "CheckForCapability" at line 155 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Session\Capabilities\DscBreakpointCapability.cs

    Side-by-side DSC module was not found.

10/19/17 6:34:41 AM [VERBOSE] - Method "SetProfileVariableInCurrentRunspace" at line 1561 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Session\PowerShellContext.cs

.

3. Exceptions about PS-Scope.

10/19/17 6:35:53 AM [ERROR] - Method "ExecuteCommand" at line 567 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Session\PowerShellContext.cs

    Runtime exception occurred while executing command:
    
    System.Management.Automation.CmdletInvocationException: The scope number '1' exceeds the number of active scopes.
    Parameter name: scopeID
    Actual value was 1. ---> System.Management.Automation.PSArgumentOutOfRangeException: The scope number '1' exceeds the number of active scopes.
    Parameter name: scopeID
    Actual value was 1.
       at System.Management.Automation.SessionStateInternal.GetScopeByID(Int32 scopeID)
       at System.Management.Automation.SessionStateInternal.GetScopeByID(String scopeID)
       at System.Management.Automation.SessionStateInternal.GetVariableTableAtScope(String scopeID)
       at Microsoft.PowerShell.Commands.VariableCommandBase.GetMatchingVariables(String name, String lookupScope, Boolean& wasFiltered, Boolean quiet)
       at Microsoft.PowerShell.Commands.GetVariableCommand.ProcessRecord()
       at System.Management.Automation.Cmdlet.DoProcessRecord()
       at System.Management.Automation.CommandProcessor.ProcessRecord()
       --- End of inner exception stack trace ---
       at System.Management.Automation.Runspaces.PipelineBase.Invoke(IEnumerable input)
       at System.Management.Automation.Runspaces.Pipeline.Invoke()
       at System.Management.Automation.PowerShell.Worker.ConstructPipelineAndDoWork(Runspace rs, Boolean performSyncInvoke)
       at System.Management.Automation.PowerShell.CoreInvokeHelper[TInput,TOutput](PSDataCollection`1 input, PSDataCollection`1 output, PSInvocationSettings settings)
       at System.Management.Automation.PowerShell.CoreInvoke[TInput,TOutput](PSDataCollection`1 input, PSDataCollection`1 output, PSInvocationSettings settings)
       at System.Management.Automation.PowerShell.CoreInvoke[TOutput](IEnumerable input, PSDataCollection`1 output, PSInvocationSettings settings)
       at System.Management.Automation.PowerShell.Invoke[T](IEnumerable input, IList`1 output, PSInvocationSettings settings)
       at System.Management.Automation.PowerShell.InvokeWithDebugger(IEnumerable`1 input, IList`1 output, PSInvocationSettings settings, Boolean invokeMustRun)
       at System.Management.Automation.ScriptDebugger.ProcessCommand(PSCommand command, PSDataCollection`1 output)
       at Microsoft.PowerShell.EditorServices.Session.PowerShell4Operations.ExecuteCommandInDebugger[TResult](PowerShellContext powerShellContext, Runspace currentRunspace, PSCommand psCommand, Boolean sendOutputToHost, Nullable`1& debuggerResumeAction)
       at Microsoft.PowerShell.EditorServices.PowerShellContext.ExecuteCommandInDebugger[TResult](PSCommand psCommand, Boolean sendOutputToHost)
       at Microsoft.PowerShell.EditorServices.PowerShellContext.<ExecuteCommand>d__48`1.MoveNext()

.

4. And now the to the root cause of my investigations:
   currently i'm not be able to debug PS Code inside VS-Code.
   Behavior:
   Step-over (F10) does not returns
   (not everey time, but every second call)
   workaround: jump into the Terminal window in VS-Code, set the focus (with mouse) and do a single key press => Step over returns and you can do the next step over (probably working) - the next step over after this hangs again - press any key in Terminal - continue......
   I can reproduce that with evere ps1 file that contains a few lines of code....

the following lines are from the log until the point where "Step-Over" does NOT return:
(Last Timespamt 06:050:18)

10/19/17 6:50:17 AM [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'stackTrace' with id 15

10/19/17 6:50:17 AM [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'stackTrace' with id 16

10/19/17 6:50:17 AM [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'stackTrace' with id 16

10/19/17 6:50:18 AM [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'scopes' with id 17

10/19/17 6:50:18 AM [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'scopes' with id 17

10/19/17 6:50:18 AM [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'variables' with id 18

10/19/17 6:50:18 AM [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'variables' with id 18

Waiting 1-2 Minutes and then pressing a key inside the terminal i get the following log items:

10/19/17 6:52:57 AM [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'variables' with id 19

10/19/17 6:52:57 AM [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'variables' with id 19

10/19/17 6:52:58 AM [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'variables' with id 20

10/19/17 6:52:58 AM [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'variables' with id 20

10/19/17 6:52:58 AM [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'variables' with id 21

10/19/17 6:52:58 AM [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'variables' with id 21

10/19/17 6:52:58 AM [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'variables' with id 22

10/19/17 6:52:58 AM [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'variables' with id 22

10/19/17 6:52:59 AM [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'next' with id 23

10/19/17 6:52:59 AM [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'next' with id 23

Regards
Werner

PSVersiontable:
Name Value

---

PSVersion 6.0.0-beta.8
PSEdition Core
GitCommitId v6.0.0-beta.8
OS Linux 4.10.0-37-generic #41~16.04.1-Ubuntu SMP Fri Oct 6 22:42:59 UTC 2017
Platform Unix
PSCompatibleVersions {1.0, 2.0, 3.0, 4.0...}
PSRemotingProtocolVersion 2.3
SerializationVersion 1.1.0.1
WSManStackVersion 3.0

[rkeithhill]

Thanks for the great bug report! Some of this is obvious like we shouldn't be searching for DSC with a path like C:\.... The other stuff will take more digging into.

[rkeithhill]

I've got a dev environment set up on Ubuntu 16.04 now. I can repro the problem and I think I have a fix but need to run it by @daviwil.

[WernerMairl]

Ok, i see that the PR #557 was closed for technical reasons....

Now i try to find a deeper understanding of the code behind the problem - some stupid question here - any hep is welcome

basically we are talking about the following piece of code (with the fix)

        private async Task<ConsoleKeyInfo> ReadKeyAsync(CancellationToken cancellationToken)
        {
            return await
                Task.Factory.StartNew(
                    () =>
                    {
                        ConsoleKeyInfo keyInfo;

                        lock (this.readKeyLock)
                        {
                            if (cancellationToken.IsCancellationRequested)
                            {
                                throw new TaskCanceledException();
                            }
                            else if (this.bufferedKey.HasValue)
                            {
                                keyInfo = this.bufferedKey.Value;
                                this.bufferedKey = null;
                            }
                            else
                            {
                                keyInfo = Console.ReadKey(true);

                                if (cancellationToken.IsCancellationRequested)
                                {
                                    this.bufferedKey = keyInfo;
                                    throw new TaskCanceledException();
                                }
                            }
                        }

                        return keyInfo;
                    });
        }

basic intent that i can see:
Task returns (as completed) with result if there is a key pressed by the user.
it returns canceled if there is a Cancellationrequest on the CancellationToken

Fact: ReadKey waits until a key is available (https://msdn.microsoft.com/en-us/library/x3h8xffw(v=vs.110).aspx).

Question: Why we have a problem only inside the Linux implementation and not in Windows ?

i must assume some other "strange" behavior or dependency between a while loop outside the method, the CancellationToken and the buffered-Key....
probably the lock protects (synchronizes) the writes to the bufferedKey, but why that buffer with the length of 1 ?

please send me in the right direction....

Werner

[ryangribble]

I've got this same problem on OSX for a few releases now and somehow only just found these logged issues of others experiencing it

[jackmusick]

I'd like to confirm I'm still having this issue. Here's my original post. I have tested this on brand new installs of both macOS and Ubuntu with the same results.

[joejank]

EditorServices.log
I am having this same issue and attaching the above log in the hope that this move this issue forward.
The above is on MacOS.