Status Update
Comments
vi...@google.com <vi...@google.com>
om...@gmail.com <om...@gmail.com> #2
Build: AI-191.8026.42.35.5977832, 201910302259,
AI-191.8026.42.35.5977832, JRE 1.8.0_202-release-1483-b03x64 JetBrains s.r.o, OS Windows 10(amd64) v10.0 , screens 1920x1080, 2560x1440, 1920x1080
AS: 3.5.2; Android Gradle Plugin: 3.5.1; Gradle: 5.4.1; NDK: from local.properties: 20.0.5594570, latest from SDK: (not found); LLDB: LLDB 3.1 (revision: 3.1.4508709); CMake: from local.properties: (not specified), latest from SDK: 3.10.2, from PATH: (not found)Source: user_sentiment_feedback
ar...@google.com <ar...@google.com>
em...@google.com <em...@google.com> #3
From the attached log, I see that there is a failure happening in SafeFileOutputStream.java, which is a part of IntelliJ platform, and was refactored in the following CL by JB to handle various failure modes:
This fix was merged into Android Studio in version 3.6.
om...@gmail.com <om...@gmail.com> #4
Android Studio 4.0 Canary 9 Build #AI-193.5233.102.40.6137316
JDK: 1.8.0_212-release; VM: OpenJDK 64-Bit Server VM; Vendor: JetBrains s.r.o
OS: Windows 10
From memory I can say that the problem has not been resolved in 3.6 and it still persists in 4.0c9 actually. I was just thinking about this issue yesterday because it is too easy to forget you are not supposed to modify files while debugging. Or rather that one is expected to stop debugging before editing files. While technically... It almost makes sense... Since Android Studio does not have the "Edit and continue" feature like Visual Studio does (to a limited degree)... But this issue still hinders workflow.
I think the bug has slightly changed in 4.0c9 but the effect is the same. Under certain conditions (possibly if there is an active breakpoint in the file... Or currently the debugger has stopped in it... Not entirely sure...) the file will refuse to save. There will be a notification in this case as soon as window looses focus (if I switch to a Chrome window for example). The notification will appear also if I press Ctrl-S explicitly.
But sometimes, it just silently fails to save. Which is worse. I have spent a few minutes staring at a bit of code where a simple assign to a variable "failed". And after adding code to understand the issue, a few "recompiles" later I noticed that the debugger started to step through empty lines source code. That was a clear indication that something is wrong with the file content on the drive the compiler was working with. This situation can then be fixed by stopping the debugger, making a small change like adding a space, saving, removing the extra space, saving again, recompile, run.
I was able to reproduce the first issue easily. But the silent fail one is rather rare. The log is attached. I have added a little more log to provide context since the same part of the code (com.intellij.openapi.vfs.newvfs.persistent) seems to report some other issue but it could be related. And at the end there is a possibly related exception when I was stopping the debugger to be able to save the file.
Note: filenames and paths have been changed for privacy reasons, but were consistently replaced in the log snippet.
If needed I can try to reproduce the issue in 3.6 as well and provide logs? I assumed info on the latest build was more interesting.
em...@google.com <em...@google.com> #5
1. The exceptions at the top of the log file come from the IntelliJ framework. For instance, the top exception in the logs seems to indicate that IDE failed to serialize its own internal symbol tables to a file.
Could there be something outside the IDE that's preventing it from accessing the file system? Maybe the native debugger is creating some temporary files and triggering that external system? Is your project stored on a special file system (e.g., auto-sync to Google drive, or a special file scanner, etc.)?
2. SafeFileOutputStream error also comes from the IntelliJ framework, and is about saving the source file in the project. Maybe disabling safe writes in the IDE settings can help. Can you try it?
File | Settings | Appearance and Behavior | System Settings | Use "safe write"
3. The LLDBDriverException about removing the breakpoint seems benign, because it came 2 seconds after the debugging session was terminated, and after lldb-server process has exited.
om...@gmail.com <om...@gmail.com> #6
What is interesting is that I also cannot trigger the issue on some files (or at least this is how it seems), but on the file that is the focus of development it happens every time. Do you see any reasons why that could happen?
I have about 35 breakpoints set. Some disabled. Muting breakpoints doesn't help the issue (save still fails). Save fails only if I change the file - saving an unmodified file seems to be filtered out (nice!). But for example I add a space, hit ctrl-s and I get the notification. Dismiss notification, press ctrl-s again and the notification doesn't appear again. Add one more space, save -> notification.
I am using an HP Elitebook 850 G4 (X4B23AV): i7-7600U @ 2.8GHz with (turbo up to 3.9GHz), 16GB or RAM, Samsung SSD 960 Pro NVMe. NOD32 antivirus.
1. What I did to try and help was to create a file operations capture using ProcMon and included the Idea log extract for the time instance. I see that ekrn (Nod32) is involved, TSVN cache is meddling and SearchProtocolHost of course cannot stay away. So there are some candidates for interference. If your deeper insight into the issue and the code helps pinpoint the culprit please let me know.
It could be size related - larger files take longer to scan/index...
If I should loosen the event filter in ProcMon to include some other files / extensions please let me know.
Disabling real-time scanner of Nod32 did not help. But honestly... the source files can likely be excluded from scanning. I thought they already were since I upgraded to Nod32 from the default Windows Defender... "scanner".
2. Disabling "safe write" didn't appear to have an effect.
3. Ah, OK.
om...@gmail.com <om...@gmail.com> #7
The attached screenshot is from the Process Monitor where the only non-default filter applied was to show only the lines where the Path contains the filename of the file I am trying to save (without the extension).
Now the trace seems to indicate that only studio64.exe and clangd.exe are accessing the file during the save operations.
What is interesting is that what the file access sequence looks like:
1. First the cpp file is opened and then immediately closed.
2. Then it is opened with a slightly different desired access, volume and file information is read.
3. At this point a temp file is created (for save save option), queried and then the temp file is closed.
4. Then the cpp file is closed.
5. Next the temp file is opened queried for attributes and then closed.
6. After the cpp file is opened again, queries extensively, then the temp file is opened and queried, then the cpp file is read in its entirety, temp file is written in its entirety some basic info is set and then both files are closed.
7. Here a call to the QueryRemoteProtocolInformation fails with INVALID PARAMETER but it looks like it is not relevant.
8. Then a different thread comes in and does another set of quick open and close with two intents. First a call to SetEndOfFileInformationFile that results in a "USER MAPPED FILE" return value and a QueryNetworkOpenInformationFile that likely reads some timestamps. And at this point (after the file is successfully closed) the exception seems to be raised in Android Studio.
There is no extra CreateFile attempt. No failed calls. Just the exception is logged.
Should it be necessary I am willing to share the entire Process Monitor capture file... But I would request that it would be sent directly to the Android Studio team and not published (here).
I thought I'd add to my previous reply that the project is stored on a regular NTFS file-system and there are no sync mechanisms in place like Google Drive or similar. At this point I am not sure what else could influence the file saving operation.
Thank you for looking into this.
em...@google.com <em...@google.com> #8
om...@gmail.com <om...@gmail.com> #9
If the repro doesn't pan out... The only other thing I can think of that I can do on my side is to compare the failed save FileOp sequence it to a successful save FileOp sequence.
And if a fix test is needed... Let me know.
Thanks!
em...@google.com <em...@google.com> #10
I've detected that the LLDBFrontend
process (which is the process that wraps the lldb DLL on the host) keeps the source file locked. This is likely a bug in LLDB.
Minimal repro instructions: (using Android Studio 4.0 Canary 9)
-
Create a new C++ project in Android Studio.
-
Add the following to native-lib.cpp:
#include "header.h"
-
Add the following function call in native-lib.cpp before the
return
statement:foo(5);
-
Add a
header.h
file to the project. The key point is that the contents of this file should be very long. For instance, I added:echo "void very_long_function() {" >> header.h for i in {1..1000}; do echo "int x_${i} = ${i}" >> header.h echo "int x_${i}_${i} = ${i} * ${i}" >> header.h done echo "}" >> header.h echo "void foo(int x) {" >> header.h echo " return x * x;" >> header.h echo "}" >> header.h
-
Set breakpoint inside the
foo()
method implementation (i.e., at linereturn x * x;
). -
Run Native-only (or auto or dual) debugger.
-
Wait until breakpoint hits at
header.h
file -
Edit the
header.h
file (e.g., add/remove some text). Save (Hit Ctrl+S).
Expected result: Save successful
Actual Result: Save fails with error:
- If safe-write is enabled:
...\MyApplication\app\src\main\cpp\header.h Unable to open file for writing
- If safe-write is disabled:
...\MyApplication\app\src\main\cpp\header.h (The requested operation cannot be performed on a file with a user-mapped section open)
Notes: This seems like an LLDB issue. Android Studio ships with LLDB 7.0.0; so this issue might have already been fixed in a newer LLDB (8.0.0 or 9.0.0). In fact, I tried reproducing this issue with standalone LLDB on Windows host (i.e., a win32 binary, rather than Android), but LLDB 8.0 and 9.0 versions did not hit the same problem. I did not have LLDB 7.0.0 compiled for Windows (it's not included in LLVM 7.0.0 prebuilts bundle), so I could not verify this bug on it.
A wild guess: When ran on the terminal, LLDB prints a fragment of the source code around the hitting breakpoint. I suspect that this piece of code tries to read the source file, and maybe, just maybe, for large files, it tries to be smart and does a memory mapping.
om...@gmail.com <om...@gmail.com> #11
I can confirm that I see the process LLDBFrontend.exe creating a file mapping using the CreateFileMapping function.
For fun I tried editing the file with Notepad++ first in user mode and then with elevated Admin permissions. Both saves failed further confirming the lock.
And then... I thought "Hey, I sometimes use VisualStudio side-by-side... And I don't ever remember it being unable to save a file, even while I was debugging stuff on Android at the same time..."
Here is the really interesting thing: MS Visual Studio can save the file that is memory mapped by LLDBFrontend... ? ?!
I didn't have time for a deep investigation (need to push forward on my project), but I did capture the file ops in process monitor... And attached them to this message.
While the result is unexpected, my reasoning is that perhaps rather than wait for a "maybe fix" in LLDB 8 or 9... There might be a way instead to make AndroidStudio work in such situations in the future.
Note:
MS Visual Studio was used in the "projecless mode" - only this one single CPP file was opened. Weird that the ipch file is created anyway. Maybe for color highlighting and intelli-sense purposes...
P.s.: I really don't like msdev.exe polling the file for info ALL the time. Please don't copy that part of the behaviour. :( There are file change notification functions in the OS for that purpose. And I suppose it is now clearer why msdev.exe is so slow sometimes - it shows the general approach to things and what passes as an OK solution.
em...@google.com <em...@google.com> #12
Debugging LLDB on the host, I noticed that the page mapping occurs when an expression evaluation request is sent from the IDE to LLDB. So, LLDB's expression evaluation mechanism (used in watch expressions, hovering over variables, etc.) seems to be causing this problem.
Need to dig deeper to find the exact problem inside LLDB, but since LLDB is
em...@google.com <em...@google.com> #13
The following shows that LLDB prefers not using mmap for small files, but uses mmap for large files:
Code Fragment:
308: static bool shouldUseMmap(...) {
...
321: // We don't use mmap for small files because this can severely fragment our
322: // address space.
323: if (MapSize < 4 * 4096 || MapSize < (unsigned)PageSize)
324: return false;
...
361: }
Sample Stack Trace:
liblldb.dll!shouldUseMmap(void * FD, unsigned __int64 FileSize, unsigned __int64 MapSize, long Offset, bool RequiresNullTerminator, int PageSize, bool IsVolatile) Line 323
at c:\src\llvm-project\llvm\lib\support\memorybuffer.cpp(327)
liblldb.dll!getOpenFileImpl<llvm::WritableMemoryBuffer>(void * FD, const llvm::Twine & Filename, unsigned __int64 FileSize, unsigned __int64 MapSize, __int64 Offset, bool RequiresNullTerminator, bool IsVolatile) Line 446
at c:\src\llvm-project\llvm\lib\support\memorybuffer.cpp(446)
liblldb.dll!getFileAux<llvm::WritableMemoryBuffer>(const llvm::Twine & Filename, __int64 FileSize, unsigned __int64 MapSize, unsigned __int64 Offset, bool RequiresNullTerminator, bool IsVolatile) Line 254
at c:\src\llvm-project\llvm\lib\support\memorybuffer.cpp(254)
liblldb.dll!llvm::WritableMemoryBuffer::getFile(const llvm::Twine & Filename, __int64 FileSize, bool IsVolatile) Line 261
at c:\src\llvm-project\llvm\lib\support\memorybuffer.cpp(261)
liblldb.dll!lldb_private::FileSystem::CreateDataBuffer(const llvm::Twine & path, unsigned __int64 size, unsigned __int64 offset) Line 294
at c:\src\llvm-project\lldb\source\host\common\filesystem.cpp(294)
liblldb.dll!lldb_private::FileSystem::CreateDataBuffer(const lldb_private::FileSpec & file_spec, unsigned __int64 size, unsigned __int64 offset) Line 310
at c:\src\llvm-project\lldb\source\host\common\filesystem.cpp(310)
liblldb.dll!lldb_private::SourceManager::File::CommonInitializer(const lldb_private::FileSpec & file_spec, lldb_private::Target * target) Line 459
at c:\src\llvm-project\lldb\source\core\sourcemanager.cpp(459)
liblldb.dll!lldb_private::SourceManager::File::File(const lldb_private::FileSpec & file_spec, lldb_private::Target * target) Line 397
at c:\src\llvm-project\lldb\source\core\sourcemanager.cpp(397)
If I remove the MapSize < 4*4096 || MapSize < (unsigned)PageSize
condition (i.e., force no-mmap), then the file locking does not happen, and Android Studio can save files.
em...@google.com <em...@google.com> #14
LLDB's SourceManager class keeps a m_last_file_sp
shared pointer to some "last file".
When we hit a breakpoint in some large source file Foo.cc
, the memory mapping for Foo.cc
is saved at SourceManager::m_last_file_sp
until the next breakpoint hits. During this time, we cannot write to the Foo.cc
file.
When the next breakpoint hits, then a new SourceManager::File
object is created, which replaces the m_last_file_sp
. The old shared_ptr
gets deleted, and the new one replaces it.
If the next breakpoint hit is also in Foo.cc
file, the replaced object also contains a memory mapping of Foo.cc
, and therefore, we still cannot write to the file.
If the next breakpoint hit is in some Bar.cc
, then the m_last_file_sp
gets overridden, he File
object (and as a result, the memory mapping for Foo.cc
) get deleted, and therefore, we can start writing to Foo.cc
.
om...@gmail.com <om...@gmail.com> #15
It is still interesting to see that Visual Studio manages to save the same file, while it remains locked for everyone else. Any ideas why that might be? The memory mapping is clearly still there and Notepad++ cannot write the file, just like Android Studio.
em...@google.com <em...@google.com> #16
I found something very interesting. LLDB also has a SourceFileCache
, which is supposed to cache the shared_pointer
s of File
s. However, there's a bug in the LLDB source code that causes it to only cache one (the most recently used) entry!
It's very simple. The file_spec
variable at
FileSpec file_spec = file_sp.GetFileSpec();
This, in fact, works in our favor that, once we hit a breakpoint, not only m_last_file_sp
gets overwritten, but also the single shared pointer entry in the cache gets overwritten. If this bug hadn't existed, large files would never be writable once any breakpoint in them hits.
em...@google.com <em...@google.com> #17
Regarding #15: I do not know how Visual Studio manages to modify locked files that are not modifiable by other editors.
om...@gmail.com <om...@gmail.com> #18
Heh, incidentally I am also working on a Cache object at the moment. I have way more than one object in Cache. And that is actually the problem - I need to write code to evict "not needed" objects depending on memory pressure.
It would be interesting to see in the recorded trace how MS Visual Studio does it. But the deadline approaches so curiosity will need to wait.
em...@google.com <em...@google.com> #19
It looks like not all Windows File APIs are treated the same.
Fundamental file operations in Android Studio are inherited from the IntelliJ platform, so we'll have to file a bug against JetBrains.
om...@gmail.com <om...@gmail.com> #20
Thanks for sharing the link you found.
A different approach in IntelliJ may prevent similar write issues in other cases as well.
em...@google.com <em...@google.com> #22
Android Studio 4.2 Canary 11 (to be released this week) will include a new LLDB (version 11) that contains the fixes in
om...@gmail.com <om...@gmail.com> #23
em...@google.com <em...@google.com> #24
Just FYI, I didn't enable the LLDB flag in Android Studio 4.2 canary 11, but it's still easy to test the behavior by adding the LLDB startup command:
settings set use-source-cache false
Once it's out and we verify it, I'll enable the flag for the next canary.
om...@gmail.com <om...@gmail.com> #25
I added the LLDB startup command already. It doesn't seem to interfere with debugging in Android Studio 4.2 canary 10 and I might forget later.
I will report how it behaves on my system.
om...@gmail.com <om...@gmail.com> #26
The new update arrived and I installed the Android Studio 4.2 canary 11. If it matters, I first attempted an update of canary 10 and after I experienced problems, I also tried a clean zip unpack from the web.
With canary 11 I am unable to debug the app at all. It appears there is a problem in the debugger - device handshake and all debug attempts end with a "popup"/baloon from the debug tab at the bottom of the screen stating:
Debugger process finished with exit code -1073741515 (0xC0000135). Rerun 'app'
The debug console reads:
09/18 10:07:35: Launching 'app' on bq Aquaris X5 Plus.
App restart successful without requiring a re-install.
$ adb shell am start -n "com.foo.app/com.foo.app.MainActivity" -a android.intent.action.MAIN -c android.intent.category.LAUNCHER -D
Waiting for application to come online: com.foo.app.test | com.foo.app
Waiting for application to come online: com.foo.app.test | com.foo.app
Connected to process 7488 on device 'bq-aquaris_x5_plus-XM023171'.
Capturing and displaying logcat messages from application. This behavior can be disabled in the "Logcat output" section of the "Debugger" settings page.
W/ActivityThread: Application com.foo.app is waiting for the debugger on port 8100...
I/System.out: Sending WAIT chunk
Waiting for application to come online: com.foo.app.test | com.foo.app
Connecting to com.foo.app
Now Launching Native Debug Session
com.intellij.execution.ExecutionFinishedException: Execution finished
Process finished with exit code 0
I have tried debugging the app with the settings set use-source-cache false
as well as without the LLDB startup command, hoping to incite the default behaviour. Both failed.
The log file is attached to provide further clues to what could be wrong.
For the time being I will switch to Canary 10 for development but I am happy to try other things in Canary 11 should you find that helpful.
Thank you for all your effort. I am really looking forward to being able to save large C++ files with confidence.
em...@google.com <em...@google.com> #27
The new LLDB in Canary 11 uses Python38. But, we noticed just after Canary 11 release that the download bundle is missing the python38.dll file. We fixed this in Canary 12.
If you install Python 3.8 (64-bit) to your machine (%PATH%
variable, then debugger will be able to use the python38.dll from that installation. Sorry for the problem.
// Or, you can copy a 64-bit Python38.dll file into your distribution at $ANDROID_STUDIO/bin/lldb/bin/ directory.
// Or, you can wait another week until canary 12
om...@gmail.com <om...@gmail.com> #28
Thank you for the Python tip. LLDB almost works now for me. I tried the Canary 12 and now it looks like LLDB gets stuck while updating the C:\Users\user\.lldb\module_cache\remote-android\
content. Every time I run it a single file gets transferred and then the debug session hangs.
It looks like some folders were renamed in cache:
New:
09/24/2020 04:25 PM <DIR> .
09/24/2020 04:25 PM <DIR> ..
09/24/2020 04:25 PM 724,940 boot-conscrypt.oat
1 File(s) 724,940 bytes
Old:
Directory of C:\Users\user\.lldb\module_cache\remote-android\.cache\7B52FA74-0000-0000-0000-000000000000
10/16/2019 10:50 AM <DIR> .
10/16/2019 10:50 AM <DIR> ..
10/16/2019 10:50 AM 724,940 boot-conscrypt.oat
10/16/2019 10:50 AM 1,097,596 boot-conscrypt.oat.sym
2 File(s) 1,822,536 bytes
If ran the debugger again, I think the next file I would get from the device is the boot-conscrypt.oat.sym
. I tried restarting the debug session for about half an hour but it's probably better I wait for the Canary 13 release... Or can you recommend a hack for Canary 12? :)
Thank you for your all your help.
em...@google.com <em...@google.com> #29
This is unexpected. Can you delete your ~/.lldb (or ~/.lldb/module_cache) directory and retry?
om...@gmail.com <om...@gmail.com> #30
I renamed the .lldb folder to move it out of the way. And the problem did go away. Debugger is working now. If it is useful in any way I can offer the working and broken .lldb folder content for analysis of what went wrong.
I have also been testing the save operation as much as possible. So far it has been working great and I observed no issues. It almost feels wrong... whenever I press save now, while debugging. Thank you for fixing this. It may be just a "nuisance" to some, but on me it had a huge impact. I developed a "file save sequence" routine to work around it in previous versions: Save, click OK on error dialog, click stop debugging, click in the file I want to save, add a space, save, remove a space, save.
Now for coding nirvana, all that would need to go away are the file locks on .so files while the debugger is running. That way I could just adjust a bit of code (while debugging), save and press debug again to apply changes... I won't ask for "edit and continue" feature like in Visual Studio (for local processes only)... Unless... Do you think it's even possible? O=)
em...@google.com <em...@google.com> #31
I'm glad we solved the source file locking problem.
Now for coding nirvana, all that would need to go away are the file locks on .so files while the debugger is running. That way I could just adjust a bit of code (while debugging), save and press debug again to apply changes...
For this, I don't have an easy fix inside Android Studio at the moment. But, I tried to find a workaround for you, and maybe this trick can help:
- Run/Debug Configurations > select your app config > Before Launch > + > Run External tool
- Insert this:
- Program: C:\Windows\System32\taskkill.exe
- Arguments: /IM "LLDBFrontend.exe" /F /FI "username ne administrator"
- Make sure you move the new command above "Gradle-aware Make"
Then, you can use the "Rerun" button on the debugger UI to restart debug session with your saved changes. This will make sure the program that keeps those .so files locked is force-killed before a Gradle re-build. (the "username ne administrator" is just to make sure taskkill does not throw an error if the process is not running, so it becomes a no-op). HTH.
em...@google.com <em...@google.com>
om...@gmail.com <om...@gmail.com> #32
Sorry to open the issue again by replying... But I just wanted to thank you for your super helpful tip. This was truly above and beyond. I deeply appreciate you taking the time to look into a workaround. It seems to work fine and opens a whole avenue of things that can be done with build events.
I was using the pre/post-build events in a similar fashion in Visual Studio before but it didn't occur to me to repeat the pattern in Android Studio. Clearly I do not know Android Studio as well as I should... I didn't know the "build events even existed in Android studio.
Even with your instructions I was staring at that dialog for a good while before I noticed there was a "Before Launch" section at the bottom of the dialog. For some reason a lot of padding is between the "Launch Options" section and the "Before Launch" section. My configurations dialog size was a little small by default... Maybe that padding can be shrunk down a bit. Uh I see what the problem is... Those tabs have a fixed amount of space reserved. Tough call. Needs redesign.
Anyway... Awesome! Please mark the issue as fixed.
Description
AI-191.8026.42.35.5900203, JRE 1.8.0_202-release-1483-b03x64 JetBrains s.r.o, OS Windows 10(amd64) v10.0 , screens 1920x1080, 2560x1440, 1920x1080
AS: 3.5.1; Android Gradle Plugin: 3.5.1; Gradle: 5.4.1; NDK: from local.properties: 20.0.5594570, latest from SDK: (not found); LLDB: LLDB 3.1 (revision: 3.1.4508709); CMake: from local.properties: (not specified), latest from SDK: 3.10.2, from PATH: (not found)Source: user_sentiment_feedback
While a native debug session is active, it is quite frequently not possible to save the a source file open in AS.
Problem tends to go away is the application debugging is stopped. However this problem coupled with issue:143448302 heavily impacts development efficiency as it may take 3-5 minutes to successfully re-start a debug session.