Fix microsoft#914: Multiple fast opening of files causes GetAnalysisA…

…sync to return old analysis (microsoft#919)

* Fix microsoft#914: Multiple fast opening of files causes GetAnalysisAsync to return old analysis

* Disable out of order analysis for the cases when current session is small

src/Analysis/Ast/Impl/Analyzer/PythonAnalyzer.cs

@@ -217,14 +217,16 @@ private void AnalyzeDocument(AnalysisModuleKey key, PythonAnalyzerEntry entry, I
         }
 
         private bool TryCreateSession(DependencyGraphSnapshot<AnalysisModuleKey, PythonAnalyzerEntry> snapshot, PythonAnalyzerEntry entry, CancellationToken cancellationToken, out PythonAnalyzerSession session) {
+            var analyzeUserModuleOutOfOrder = false;
             lock (_syncObj) {
                 if (_currentSession != null) {
                     if (_currentSession.Version > snapshot.Version || _nextSession != null && _nextSession.Version > snapshot.Version) {
                         session = null;
                         return false;
                     }
 
-                    if (_version > snapshot.Version && !_currentSession.IsCompleted && entry.IsUserModule) {
+                    analyzeUserModuleOutOfOrder = !_currentSession.IsCompleted && entry.IsUserModule && _currentSession.AffectedEntriesCount >= _maxTaskRunning;
+                    if (_version > snapshot.Version && analyzeUserModuleOutOfOrder) {
                         session = CreateSession(null, entry, cancellationToken);
                         return true;
                     }
@@ -253,8 +255,8 @@ private bool TryCreateSession(DependencyGraphSnapshot<AnalysisModuleKey, PythonA
                 }
 
                 _currentSession.Cancel();
-                _nextSession = session = CreateSession(walker, entry.IsUserModule ? entry : null, cancellationToken);
-                return entry.IsUserModule;
+                _nextSession = session = CreateSession(walker, analyzeUserModuleOutOfOrder ? entry : null, cancellationToken);
+                return analyzeUserModuleOutOfOrder;
             }
         }
 

src/Analysis/Ast/Impl/Analyzer/PythonAnalyzerSession.cs

@@ -58,6 +58,7 @@ public bool IsCompleted {
         }
 
         public int Version { get; }
+        public int AffectedEntriesCount { get; }
 
         public PythonAnalyzerSession(IServiceManager services,
             IProgressReporter progress,
@@ -73,6 +74,7 @@ public PythonAnalyzerSession(IServiceManager services,
             _analysisCompleteEvent = analysisCompleteEvent;
             _startNextSession = startNextSession;
             Version = version;
+            AffectedEntriesCount = walker.AffectedValues.Count;
             _walker = walker;
             _entry = entry;
             _state = State.NotStarted;
@@ -99,7 +101,7 @@ public void Start(bool analyzeEntry) {
             if (analyzeEntry && _entry != null) {
                 Task.Run(() => Analyze(_entry, Version, _cts.Token), _cts.Token).DoNotWait();
             } else {
-                StartAsync(_walker).ContinueWith(_startNextSession).DoNotWait();
+                StartAsync().ContinueWith(_startNextSession).DoNotWait();
             }
         }
 
@@ -109,11 +111,11 @@ public void Cancel() {
             }
         }
 
-        private async Task StartAsync(IDependencyChainWalker<AnalysisModuleKey, PythonAnalyzerEntry> walker) {
-            _progress.ReportRemaining(walker.Remaining);
+        private async Task StartAsync() {
+            _progress.ReportRemaining(_walker.Remaining);
 
             lock (_syncObj) {
-                var notAnalyzed = walker.AffectedValues.Count(e => e.NotAnalyzed);
+                var notAnalyzed = _walker.AffectedValues.Count(e => e.NotAnalyzed);
 
                 if (_isCanceled && notAnalyzed < _maxTaskRunning) {
                     _state = State.Completed;
@@ -124,15 +126,15 @@ private async Task StartAsync(IDependencyChainWalker<AnalysisModuleKey, PythonAn
 
             var cancellationToken = _cts.Token;
             var stopWatch = Stopwatch.StartNew();
-            foreach (var affectedEntry in walker.AffectedValues) {
+            foreach (var affectedEntry in _walker.AffectedValues) {
                 affectedEntry.Invalidate(Version);
             }
 
-            var originalRemaining = walker.Remaining;
+            var originalRemaining = _walker.Remaining;
             var remaining = originalRemaining;
             try {
-                _log?.Log(TraceEventType.Verbose, $"Analysis version {walker.Version} of {originalRemaining} entries has started.");
-                remaining = await AnalyzeAffectedEntriesAsync(walker, stopWatch, cancellationToken);
+                _log?.Log(TraceEventType.Verbose, $"Analysis version {_walker.Version} of {originalRemaining} entries has started.");
+                remaining = await AnalyzeAffectedEntriesAsync(stopWatch, cancellationToken);
             } finally {
                 _cts.Dispose();
                 stopWatch.Stop();
@@ -150,8 +152,8 @@ private async Task StartAsync(IDependencyChainWalker<AnalysisModuleKey, PythonAn
 
             var elapsed = stopWatch.Elapsed.TotalMilliseconds;
 
-            SendTelemetry(elapsed, originalRemaining, remaining, walker.Version);
-            LogResults(elapsed, originalRemaining, remaining, walker.Version);
+            SendTelemetry(elapsed, originalRemaining, remaining, _walker.Version);
+            LogResults(elapsed, originalRemaining, remaining, _walker.Version);
         }
 
         private void SendTelemetry(double elapsed, int originalRemaining, int remaining, int version) {
@@ -201,10 +203,12 @@ private void LogResults(double elapsed, int originalRemaining, int remaining, in
             }
         }
 
-        private async Task<int> AnalyzeAffectedEntriesAsync(IDependencyChainWalker<AnalysisModuleKey, PythonAnalyzerEntry> walker, Stopwatch stopWatch, CancellationToken cancellationToken) {
+        private async Task<int> AnalyzeAffectedEntriesAsync(Stopwatch stopWatch, CancellationToken cancellationToken) {
             IDependencyChainNode<PythonAnalyzerEntry> node;
             var remaining = 0;
-            while ((node = await walker.GetNextAsync(cancellationToken)) != null) {
+            var ace = new AsyncCountdownEvent(0);
+
+            while ((node = await _walker.GetNextAsync(cancellationToken)) != null) {
                 bool isCanceled;
                 lock (_syncObj) {
                     isCanceled = _isCanceled;
@@ -216,14 +220,16 @@ private async Task<int> AnalyzeAffectedEntriesAsync(IDependencyChainWalker<Analy
                     continue;
                 }
 
-                if (Interlocked.Increment(ref _runningTasks) >= _maxTaskRunning || walker.Remaining == 1) {
-                    Analyze(walker, node, stopWatch, cancellationToken);
+                if (Interlocked.Increment(ref _runningTasks) >= _maxTaskRunning || _walker.Remaining == 1) {
+                    Analyze(node, null, stopWatch, cancellationToken);
                 } else {
-                    StartAnalysis(walker, node, stopWatch, cancellationToken).DoNotWait();
+                    StartAnalysis(node, ace, stopWatch, cancellationToken).DoNotWait();
                 }
             }
 
-            if (walker.MissingKeys.All(k => k.IsTypeshed)) {
+            await ace.WaitAsync(cancellationToken);
+
+            if (_walker.MissingKeys.All(k => k.IsTypeshed)) {
                 Interlocked.Exchange(ref _runningTasks, 0);
                 bool isCanceled;
                 lock (_syncObj) {
@@ -239,36 +245,37 @@ private async Task<int> AnalyzeAffectedEntriesAsync(IDependencyChainWalker<Analy
         }
 
 
-        private Task StartAnalysis(IDependencyChainWalker<AnalysisModuleKey, PythonAnalyzerEntry> walker, IDependencyChainNode<PythonAnalyzerEntry> node, Stopwatch stopWatch, CancellationToken cancellationToken)
-            => Task.Run(() => Analyze(walker, node, stopWatch, cancellationToken), cancellationToken);
+        private Task StartAnalysis(IDependencyChainNode<PythonAnalyzerEntry> node, AsyncCountdownEvent ace, Stopwatch stopWatch, CancellationToken cancellationToken)
+            => Task.Run(() => Analyze(node, ace, stopWatch, cancellationToken), cancellationToken);
 
         /// <summary>
         /// Performs analysis of the document. Returns document global scope
         /// with declared variables and inner scopes. Does not analyze chain
         /// of dependencies, it is intended for the single file analysis.
         /// </summary>
-        private void Analyze(IDependencyChainWalker<AnalysisModuleKey, PythonAnalyzerEntry> walker, IDependencyChainNode<PythonAnalyzerEntry> node, Stopwatch stopWatch, CancellationToken cancellationToken) {
+        private void Analyze(IDependencyChainNode<PythonAnalyzerEntry> node, AsyncCountdownEvent ace, Stopwatch stopWatch, CancellationToken cancellationToken) {
             IPythonModule module;
             try {
+                ace?.AddOne();
                 var entry = node.Value;
-                if (!entry.IsValidVersion(walker.Version, out module, out var ast)) {
+                if (!entry.IsValidVersion(_walker.Version, out module, out var ast)) {
                     _log?.Log(TraceEventType.Verbose, $"Analysis of {module.Name}({module.ModuleType}) canceled.");
                     node.Skip();
                     return;
                 }
                 var startTime = stopWatch.Elapsed;
-                AnalyzeEntry(entry, module, ast, walker.Version, cancellationToken);
+                AnalyzeEntry(entry, module, ast, _walker.Version, cancellationToken);
                 node.Commit();
 
                 _log?.Log(TraceEventType.Verbose, $"Analysis of {module.Name}({module.ModuleType}) completed in {(stopWatch.Elapsed - startTime).TotalMilliseconds} ms.");
             } catch (OperationCanceledException oce) {
-                node.Value.TryCancel(oce, walker.Version);
+                node.Value.TryCancel(oce, _walker.Version);
                 node.Skip();
                 module = node.Value.Module;
                 _log?.Log(TraceEventType.Verbose, $"Analysis of {module.Name}({module.ModuleType}) canceled.");
             } catch (Exception exception) {
                 module = node.Value.Module;
-                node.Value.TrySetException(exception, walker.Version);
+                node.Value.TrySetException(exception, _walker.Version);
                 node.Commit();
                 _log?.Log(TraceEventType.Verbose, $"Analysis of {module.Name}({module.ModuleType}) failed.");
             } finally {
@@ -278,8 +285,9 @@ private void Analyze(IDependencyChainWalker<AnalysisModuleKey, PythonAnalyzerEnt
                 }
 
                 if (!isCanceled) {
-                    _progress.ReportRemaining(walker.Remaining);
+                    _progress.ReportRemaining(_walker.Remaining);
                 }
+                ace?.Signal();
                 Interlocked.Decrement(ref _runningTasks);
             }
         }

src/Analysis/Ast/Impl/Documents/Definitions/IDocument.cs

@@ -49,7 +49,7 @@ public interface IDocument: IPythonModule, IDisposable {
         /// <summary>
         /// Returns document analysis.
         /// </summary>
-        Task<IDocumentAnalysis> GetAnalysisAsync(int waitTime, CancellationToken cancellationToken = default);
+        Task<IDocumentAnalysis> GetAnalysisAsync(int waitTime = 200, CancellationToken cancellationToken = default);
 
         /// <summary>
         /// Returns last known document AST. The AST may be out of date or null.

src/Analysis/Ast/Impl/Modules/PythonModule.cs

@@ -212,7 +212,7 @@ private void InitializeContent(string content, int version) {
             lock (AnalysisLock) {
                 LoadContent(content, version);
 
-                var startParse = ContentState < State.Parsing && _parsingTask == null;
+                var startParse = ContentState < State.Parsing && (_parsingTask == null || version > 0);
                 if (startParse) {
                     Parse();
                 }

src/Analysis/Ast/Impl/Types/LocatedMember.cs

@@ -17,6 +17,7 @@
 using System.Collections.Generic;
 using System.Linq;
 using Microsoft.Python.Analysis.Modules;
+using Microsoft.Python.Core;
 
 namespace Microsoft.Python.Analysis.Types {
     internal abstract class LocatedMember : ILocatedMember {
@@ -56,8 +57,9 @@ public virtual IReadOnlyList<LocationInfo> References {
                     }
 
                     var refs = _references
-                        .GroupBy(x => x.LocationInfo.DocumentUri)
-                        .SelectMany(g => g.Select(x => x.LocationInfo).OrderBy(x => x.Span));
+                        .Select(x => x.LocationInfo)
+                        .OrderBy(x => x.DocumentUri.AbsolutePath, StringExtensions.PathsStringComparer)
+                        .ThenBy(x => x.Span);
                     return Enumerable.Repeat(Definition, 1).Concat(refs).ToArray();
                 }
             }

src/LanguageServer/Impl/Sources/ReferenceSource.cs

@@ -142,16 +142,18 @@ private IEnumerable<string> ScanFiles(IDictionary<string, PythonAst> closedFiles
 
         private async Task AnalyzeFiles(IEnumerable<Uri> files, CancellationToken cancellationToken) {
             var rdt = _services.GetService<IRunningDocumentTable>();
+            var analysisTasks = new List<Task>();
             foreach (var f in files) {
-                Analyze(f, rdt);
+                analysisTasks.Add(GetOrOpenModule(f, rdt).GetAnalysisAsync(cancellationToken: cancellationToken));
             }
-            var analyzer = _services.GetService<IPythonAnalyzer>();
-            await analyzer.WaitForCompleteAnalysisAsync(cancellationToken);
+
+            await Task.WhenAll(analysisTasks);
         }
 
-        private static void Analyze(Uri uri, IRunningDocumentTable rdt) {
-            if (rdt.GetDocument(uri) != null) {
-                return; // Already opened by another analysis.
+        private static IDocument GetOrOpenModule(Uri uri, IRunningDocumentTable rdt) {
+            var document = rdt.GetDocument(uri);
+            if (document != null) {
+                return document; // Already opened by another analysis.
             }
 
             var filePath = uri.ToAbsolutePath();
@@ -161,7 +163,8 @@ private static void Analyze(Uri uri, IRunningDocumentTable rdt) {
                 Uri = uri,
                 ModuleType = ModuleType.User
             };
-            rdt.AddModule(mco);
+
+            return rdt.AddModule(mco);
         }
 
         private ILocatedMember GetRootDefinition(ILocatedMember lm) {

src/LanguageServer/Test/ReferencesTests.cs

@@ -70,13 +70,14 @@ def func(x):
 y = func(x)
 x = 2
 ";
-            var uri1 = TestData.GetDefaultModuleUri();
-            var uri2 = TestData.GetNextModuleUri();
 
             var code2 = $@"
-from {Path.GetFileNameWithoutExtension(uri1.AbsolutePath)} import x
+from module1 import x
 y = x
 ";
+            var uri1 = await TestData.CreateTestSpecificFileAsync("module1.py", code1);
+            var uri2 = await TestData.CreateTestSpecificFileAsync("module2.py", code2);
+
             await CreateServicesAsync(PythonVersions.LatestAvailable3X, uri1.AbsolutePath);
 
             var rdt = Services.GetService<IRunningDocumentTable>();
@@ -98,7 +99,7 @@ def func(x):
             refs[2].range.Should().Be(7, 0, 7, 1);
             refs[2].uri.Should().Be(uri1);
 
-            refs[3].range.Should().Be(1, 19, 1, 20);
+            refs[3].range.Should().Be(1, 20, 1, 21);
             refs[3].uri.Should().Be(uri2);
             refs[4].range.Should().Be(2, 4, 2, 5);
             refs[4].uri.Should().Be(uri2);