Renaming files sometimes leaves stale analysis errors saying the file does not exist #51159
Labels
devexp-lsp
Issues with analysis server's support of Language Server Protocol
legacy-area-analyzer
Use area-devexp instead.
P2
A bug or feature request we're likely to work on
Comments
|
After some further digging I cannot reproduce the issue with a clean // lib/main.dart
import 'package:bug/foo.dart';
void main() {
final Foo foo = Foo();
}
// lib/foo.dart
class Foo {}Maybe it has to do with the size of the codebase? |
keertip
added
analyzer-editing-experience
P2
|
/cc @bwilkerson @DanTup |
|
@navaronbracke are you able to reproduce this on any public codebase?
That code shouldn't affect the LSP server, only the original server protocol. Can you confirm if you hover over the |
|
I recorded the video while working on https://github.com/navaronbracke/weforza which is one of my own projects. When I hover over the |
|
@navaronbracke apologies - apparently when I moved things into that menu I lost the LSP/DAS tag that was shown. If you run the Dart: Open Extension Log command shortly after opening a project and search for I'll have a go at trying to repro using that code, thanks! |
|
I was able to reproduce this once, but I'm struggling to trigger it again with logging enabled. FWIW, I'm using LSP so I don't believe it's related to #51015. Can you reproduce the issue reliably, or is it intermittent? |
|
It says LSP for me too. I can reproduce it reliably (tested it on an arbitrary class and I also get the I tried to capture logs and reproduced the bug (on yet another arbitrary class, so that's the 3rd one where I reproduced it) Steps to reproduce
These are the logs from the |
|
@navaronbracke thanks! This log definitely shows some odd things. Even if the actual rename on disk was delayed, it shows VS Code opening the (new) file: And then the server sends the diagnostics for that file: Yet it then responds to many requests saying the file does not exist. Is it possible you could add this to your VS Code Workspace Settings ( It will automatically restart the analyzer, wait for initial analysis to complete, and then reproduce the issue and attach the file? (note: it'll contain parts of source code just like the above). That log is captured by the server and includes some additional things such as when the file system watcher event fires for the rename. I don't know if it'll be any more revealing, but it might. |
|
Huh, strange. So I added to my workspace settings. That did indeed restart the analyzer, so I waited for it to complete its analysis. I wonder if just restarting the analyzer did the trick? But then why didn't opening VSCode be sufficient? (since that would result in the analyzer starting fresh anyway) I wonder if it has anything to do with the |
|
How often did you see it before? It was after enabling the log that I couldn't reproduce it, so it's possible that's affecting some timing (and the issue is a race condition). I've removed the log but still not been able to reproduce it though. Restarting (and/or deleting I'll have another go through your previous log and see if I can find anything. It feels like maybe the rename on disk, and VS Code "opening" the newly-named file might have not been processed quickly - however, I can't come up with a reason for that unless the server was "busy", but then I'd also expect that to delay the requests that are failing to find the file. |
|
I had it consistently before enabling the log. I didn't get to reproduce it while to extra logging was enabled. Now that I turned off the logging again (the logging category in the extension logs says I've only seen it happen after switching to Dart 2.19 a few days after Flutter 3.7.0 landed on stable. I was on a 3.7.x beta release before that and didn't see it happen there (unless it started with one of the more recent 3.7.x beta releases?) I haven't been working on any other big projects since making the switch to the new Dart version so I can't really tell if it reproduces for other projects of different magnitudes. |
|
Thanks, that's good to know. It turns out that I actually had logging on when I repro'd it initially (I somehow had forgotten that I always have the instrumentation log enabled in my global settings specifically to get logs of intermittent things like this). Unfortunately my attempts to reproduce it rolled over the logs so I don't still have it. So while it's possible the log is affecting timing that make it less likely to occur, it definitely isn't preventing it. Even with logging off, I haven't managed to reproduce it since that first time. Is it possible you could run with logging enabled for a little while, and when you next see it, grab a copy of the log? The logs can get quite large and will roll over on each session start (with the last 5 or so kept). When you next see it, everything from the last instance of |
I'll try to repro with logging enabled. Once I do, I'll report back here with my logs. |
|
@DanTup I'm back! So I reproduced the issue on Log file: instrum.txt |
Sorry, I mis-remembered. They just say Do you know the exact behaviour you saw when you captured this log? In the original message at the top you said that the editor applying the changes seemed to be delayed, though in the log it appears that the edit applied those edits quite quickly. There are definitely some issues in the log - those "File does not exist" errors are the server telling VS Code it can't find the file even though VS Code just told us there is a new file with that path. I feel like there is some kind of race condition here. I'm going to try to repro, although I'm not sure if it's what's leading to the delays you're seeing. For (probably my) future reference, here's an annotated snippet from the log: |
|
I did the same thing like last time:
I did try something a bit different this time as well:
It seems that it only restores if you close the file that was renamed. |
|
@DanTup If I close the file and then rename it (so that there is no open file handle when the rename happens) everything works as expected. Could it be that the editor does things at the right pace, but because the file handle is open, it can't apply some things? Like does the open file handle lock certain actions? |
|
In the log file, it shows that VS Code "closed" the file as it was doing the rename (and opened it with a new name), so I wouldn't have expected that to make a difference. However if it seems to, perhaps here's something not right with our handling of that close. I think I have enough info to do some more targeted digging now anyway, so I'll see what I can find - thanks! |
|
I may have a reliable repro for what appears to be this issue, although I can only trigger it when moving the file from bin/main.dartimport 'package:dart_sdk_51159/foo.dart';
Foo? a;lib/foo.dartclass Foo {}Open both files side-by-side. Drag Relevant log parts: |
|
Ok, I think I understand the issue now. I think there are two optimisations I've added which are not playing nicely together.
Both of these choices appear sound. However, I think we have a race here that can cause both of these optimisations to occur when a new file is created and opened at the same time, resulting in no analysis. When I reproduce this issue with some extra logging, I see this in the logs: I believe what's happening is:
Removing either optimisation would fix the issue, but my feeling is that the one that shortcuts in didOpen is the broken one. It's looking on the disk to decide that this overlay wouldn't change anything in the servers state, but the server is behind. It should really be detecting whether the file contents are the same as the server already knows about (and if the server does not know about this file, it should consider this a new file). @bwilkerson @scheglov is there a reasonable way to get the contents of a file that the server has analyzed, without going through the sdk/pkg/analysis_server/lib/src/lsp/lsp_analysis_server.dart Lines 499 to 516 in 0add39a If we can't do this, we could remove this optimisation - although the optimisation might be reducing the frequency of the issue in #48051. |
DanTup
changed the title
DanTup
added
the
devexp-lsp
|
Every |
|
That seems to be exactly what I needed, thanks! |
|
Fixed by ec658a1. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
I recently did the switch from Dart 2.18.6 to 2.19.0 and I noticed that
the analyzer now loses track of some of its context information when renaming files.
Expected results:
In Dart 2.18.6 and earlier I was able to use my IDE to rename files and the analyzer would update the relevant imports
so I could just continue as if nothing happened.
For example:
rename filefoo.dart->bar.dartActual results
Step 1 - 4 happen as expected, but the analyzer gets confused for a while and is not able to do step 5 until after a delay.
Does this have to do with #51015 ?
I have seen the analyzer only catch up when reopening the renamed file (even after waiting longer than ten seconds)
Dart SDK version: 2.19.0 (stable) (Mon Jan 23 11:29:09 2023 -0800) on "macos_x64"
Video: https://drive.google.com/file/d/1yXe80zYXPCQ2ltMX0WTDZrJsfSgiKye7/view?usp=sharing
The text was updated successfully, but these errors were encountered: