by Interesting story happened to me the other day. Visual Studio Code, my primary C# editor on Linux, suddenly stopped working. Well, it’s debugger did. Whenever I put a breakpoint and started debugging, nice friendly message would appear in the top of the editor, saying:
And it all worked just fine before. As recently I installed a whole bunch of new tools on my Ubuntu, such as lldb, perf and lttng, I played with removing and re-adding them again, reinstalling VS Code itself, but nothing seemed to help. Surprisingly, another C# IDE that supports Linux – JetBrains Rider – also failed to debug the projects I needed (worked fine with few others, though), so I had no other choice but try to get to the bottom of it, or at least make VS Code work again.
Looking for dump files
Whenever a process crashes on my Ubuntu, it will leave a dump file. That’s the way I configured it a while ago and now this behavior would become handy again. After all, “Debug adapter process has terminated unexpectedly” sounds like something that would leave a core dump or two. And you know what, it did! I found bunch of them right in VS Code’s C# extension folder:
|
1 2 3 4 5 |
ls ~/.vscode/extensions/ms-vscode.csharp-1.14.0-beta2/.debugger #.. core_vsdbg-ui.1516818450.11328 core_vsdbg-ui.1516819369.17965 #.. |
Failing executable – vsdbg-ui – was right next to them, so it was interesting to take a look at what brought it down.
Checking the stacktrace
OK, let’s take lldb debugger and open that dump:
|
1 2 3 |
lldb-3.6 vsdbg-ui -c core_vsdbg-ui.1516818450.11328 #... (lldb) |
The first command I usually run inside of a dump is backtrace – a call stack of current thread. That’s usually a good place to start.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 |
(lldb) bt #* thread #1: tid = 0, 0x00007fa6142a8428 libc.so.6`gsignal + 56, name = 'vsdbg-ui', stop reason = signal SIGABRT # * frame #0: 0x00007fa6142a8428 libc.so.6`gsignal + 56 # frame #1: 0x00007fa6142aa02a libc.so.6`abort + 362 # frame #2: 0x00007fa612fdb6cc libcoreclr.so`PROCAbort + 124 # frame #3: 0x00007fa612fda5bb libcoreclr.so`PROCEndProcess(void*, unsigned int, int) + 235 # frame #4: 0x00007fa612d43748 libcoreclr.so`UnwindManagedExceptionPass1(PAL_SEHException&, _CONTEXT*) + 840 # frame #5: 0x00007fa612d437f9 libcoreclr.so`DispatchManagedException(PAL_SEHException&, bool) + 73 # frame #6: 0x00007fa612cb3f2a libcoreclr.so`IL_Throw(Object*) + 794 # frame #7: 0x00007fa5cadc1291 # frame #8: 0x00007fa5cb2c61b2 # frame #9: 0x00007fa612bf2d18 libcoreclr.so`MethodTable::CallFinalizer(Object*) + 600 # frame #10: 0x00007fa612c94c0e libcoreclr.so`FinalizerThread::DoOneFinalization(Object*, Thread*, int, bool*) + 334 # frame #11: 0x00007fa612c94a1a libcoreclr.so`FinalizerThread::FinalizeAllObjects(Object*, int) + 266 # frame #12: 0x00007fa612c9507e libcoreclr.so`FinalizerThread::FinalizerThreadWorker(void*) + 446 # frame #13: 0x00007fa612c30bd2 libcoreclr.so`ManagedThreadBase_DispatchOuter(ManagedThreadCallState*) + 402 # frame #14: 0x00007fa612c3142e libcoreclr.so`ManagedThreadBase::FinalizerBase(void (*)(void*)) + 94 # frame #15: 0x00007fa612c952fc libcoreclr.so`FinalizerThread::FinalizerThreadStart(void*) + 204 # frame #16: 0x00007fa612fdd342 libcoreclr.so`CorUnix::CPalThread::ThreadEntry(void*) + 306 # frame #17: 0x00007fa614b636ba libpthread.so.0`start_thread + 202 # frame #18: 0x00007fa61437a41d libc.so.6`clone + 109 |
This is excellent! I mean process failed, that’s sad, but libcoreclr.so inside of call stack means it’s .NET Core process and FinalizerThread with DispatchManagedException indicate something happened in one of object destructors and a managed exception was thrown, which eventually terminated the whole process.
As we’re talking about .NET Core, we’d better enable SOS plugin and start dealing with its managed threads and objects.
Going managed
The simplest way to get SOS plugin is to pick one from .NET Core SDK folder, which I just happened to have. After enabling it, I could run something like sos PrintException and see what exactly was that exception about.
|
1 2 3 4 5 6 |
(lldb) plugin load /usr/share/dotnet/shared/Microsoft.NETCore.App/2.0.4/libsosplugin.so (lldb) sos PrintException #dlopen(/home/pavelklimenkov/.vscode/extensions/ms-vscode.csharp-1.14.0-beta2/.debugger/libsos.so) failed /home/pavelklimenkov/.vscode/extensions/ms-vscode.csharp-1.14.0-beta2/.debugger/libsos.so: cannot open shared object file: No such file or directory |
OK, it’s complaining that libsos.so missing in current folder. No problem, I know .NET Core SDK has one, so I just copy it here and retry:
|
1 2 3 4 |
cp /usr/share/dotnet/shared/Microsoft.NETCore.App/2.0.4/libsos.so . #... (lldb) sos PrintException The current thread is unmanaged |
“The current is unmanaged”. I can deal with that, but for now, how many managed threads we’re talking about?
Analyzing threads
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 |
(lldb) sos Threads #ThreadCount: 9 #UnstartedThread: 0 #BackgroundThread: 9 #PendingThread: 0 #DeadThread: 0 #Hosted Runtime: no # Lock # ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception #XXXX 1 2c42 0000000001A70FE0 21220 Preemptive 00007FA5E4231AD0:00007FA5E4232388 0000000001A68F20 0 Ukn (Finalizer) System.NotSupportedException 00007fa5e42303a0 #XXXX 2 2c40 0000000001A88590 2020220 Preemptive 0000000000000000:0000000000000000 0000000001A68F20 0 Ukn #XXXX 3 2c45 0000000001A47F30 1021220 Preemptive 0000000000000000:0000000000000000 0000000001A68F20 0 Ukn (Threadpool Worker) #XXXX 4 2c47 00007FA5DC004BC0 1021220 Preemptive 0000000000000000:0000000000000000 0000000001A68F20 0 Ukn (Threadpool Worker) #XXXX 6 2c49 00007FA5D8004BC0 1021220 Preemptive 0000000000000000:0000000000000000 0000000001A68F20 0 Ukn (Threadpool Worker) #XXXX 5 2c4c 00007FA5CC005600 2020220 Preemptive 0000000000000000:0000000000000000 0000000001A68F20 0 Ukn #XXXX 7 2c4f 00007FA5C0005DE0 20220 Preemptive 0000000000000000:0000000000000000 0000000001A68F20 0 Ukn #XXXX 8 2c57 00007FA5B0009A50 20220 Preemptive 00007FA5E422F948:00007FA5E4230388 0000000001A68F20 0 Ukn #XXXX 9 2c66 00007FA5B8002520 20220 Preemptive 00007FA5E4228650:00007FA5E422A388 0000000001A68F20 0 Ukn |
And here’s another huge luck. Very first thread, (OSID – 2c42) had System.NotSupportedException in it. There’s also memory address next to exception, 00007fa5e42303a0, so we can look inside:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 |
(lldb) dumpobj 00007fa5e42303a0 #Name: System.NotSupportedException #MethodTable: 00007fa603e213b0 #EEClass: 00007fa60363bfb0 #Size: 152(0x98) bytes #File: /home/pavelklimenkov/.vscode/extensions/ms-vscode.csharp-1.14.0-beta2/.debugger/System.Private.CoreLib.dll #Fields: # MT Field Offset Type VT Attr Value Name #00007fa603e1c460 40001cd 8 System.String 0 instance 00007fa5e42305d0 _className #00007fa603e1f8e8 40001ce 10 ...ection.MethodBase 0 instance 0000000000000000 _exceptionMethod #00007fa603e1c460 40001cf 18 System.String 0 instance 0000000000000000 _exceptionMethodString #00007fa603e1c460 40001d0 20 System.String 0 instance 00007fa5e4202f30 _message #00007fa603db95c8 40001d1 28 ...tions.IDictionary 0 instance 0000000000000000 _data #00007fa603e1bff0 40001d2 30 System.Exception 0 instance 0000000000000000 _innerException #00007fa603e1c460 40001d3 38 System.String 0 instance 0000000000000000 _helpURL #00007fa603e1c890 40001d4 40 System.Object 0 instance 00007fa5e42304f8 _stackTrace #00007fa603e1c890 40001d5 48 System.Object 0 instance 0000000000000000 _watsonBuckets #00007fa603e1c460 40001d6 50 System.String 0 instance 0000000000000000 _stackTraceString #00007fa603e1c460 40001d7 58 System.String 0 instance 0000000000000000 _remoteStackTraceString #00007fa603e3c020 40001d8 80 System.Int32 1 instance 0 _remoteStackIndex #00007fa603e1c890 40001d9 60 System.Object 0 instance 0000000000000000 _dynamicMethods #00007fa603e3c020 40001da 84 System.Int32 1 instance -2146233067 _HResult #00007fa603e1c460 40001db 68 System.String 0 instance 0000000000000000 _source #00007fa603e3c2d0 40001dc 70 System.IntPtr 1 instance 0000000000000000 _xptrs #00007fa603e3c020 40001dd 88 System.Int32 1 instance -532462766 _xcode #00007fa603e468e8 40001de 78 System.UIntPtr 1 instance 0000000000000000 _ipForWatsonBuckets #00007fa603e1c890 40001cc 40 System.Object 0 shared static s_EDILock |
It’s _message property is not empty and we can dump it as well:
|
1 2 3 4 5 6 7 8 9 10 11 12 |
(lldb) dumpobj 00007fa5e4202f30 #Name: System.String #MethodTable: 00007fa603e1c460 #EEClass: 00007fa60363aeb8 #Size: 48(0x30) bytes #File: /home/pavelklimenkov/.vscode/extensions/ms-vscode.csharp-1.14.0-beta2/.debugger/System.Private.CoreLib.dll #String: GetObjectID #Fields: # MT Field Offset Type VT Attr Value Name #00007fa603e3c020 40001c9 8 System.Int32 1 instance 11 m_stringLength #00007fa603e20420 40001ca c System.Char 1 instance 47 m_firstChar #00007fa603e1c460 40001cb 38 System.String 0 shared static Empty |
OK, so something doesn’t support “GetObjectID” method. I wonder what exactly. Let’s get back to the thread.
Getting exception call stack
The last time PrintException didn’t work, because current thread was unmanaged. But we can link managed thread to current unmanaged one and make SOS happy.
|
1 2 3 4 5 6 7 |
(lldb) thread list #Process 0 stopped #* thread #1: tid = 0, 0x00007fa6142a8428 libc.so.6`gsignal + 56, name = 'vsdbg-ui', stop reason = signal SIGABRT # thread #2: tid = 1, 0x00007fa614b69360 libpthread.so.0`__pthread_cond_wait + 192, stop reason = signal SIGABRT # thread #3: tid = 2, 0x00007fa61436e74d libc.so.6`__poll + 45, stop reason = signal SIGABRT # thread #4: tid = 3, 0x00007fa614b6cc7d libpthread.so.0, stop reason = signal SIGABRT #.... |
Theoretically, if I connect CLR thread #1 (OSID – 2c42) to current unmanaged thread #1, it might do the trick.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
(lldb) setsostid 2c42 1 #Mapped sos OS tid 0x2c42 to lldb thread index 1 (lldb) sos PrintException #Exception object: 00007fa5e42303a0 #Exception type: System.NotSupportedException #Message: GetObjectID #InnerException: <none> #StackTrace (generated): # SP IP Function # 00007FA6124CC9E0 00007FA5CADC1291 System.Private.CoreLib.InteropServices.ni.dll!System.Runtime.InteropServices.InteropExtensions.GetObjectID(System.Object)+0x31 # 00007FA6124CC9F0 00007FA5CB2C6B5F System.Private.Interop.ni.dll!System.__ComObject.Cleanup(Boolean)+0xaf # 00007FA6124CCAB0 00007FA5CB2C61B2 System.Private.Interop.ni.dll!System.RCWFinalizer.Finalize()+0x12 # #StackTraceString: <none> #HResult: 80131515 |
Great! The stack is long enough to start googling. .NET Core is open source, after all.
Working with sources and the great reveal
It was fairly easy to find InteropExtensions.cs which holds GetObjectID method, and indeed it was throwing the exception. However, that wouldn’t explain why did it start failing now and how to stop it.
|
1 2 3 4 |
public unsafe static IntPtr GetObjectID(object obj) { throw new NotSupportedException("GetObjectID"); } |
Going up the call stack into __ComObject.Cleanup was more useful, because the only lines that call GetObjectID are lines like these:
|
1 2 |
if (InteropEventProvider.IsEnabled()) InteropEventProvider.Log.TaskRCWFinalization((long)InteropExtensions.GetObjectID(this), this.m_refCount); |
It’s some sort of logging which, according to IsEnabled method name, may or may not be enabled. Going into InteropEventProvider.IsEnabled doesn’t lead to an insight, but triggers an idea.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 |
public static readonly InteropEventProvider Log = new InteropEventProvider(); #if ENABLE_WINRT internal new static bool IsEnabled() { // The InteropEventProvider class constructor should create an instance of InteropEventProvider and assign // it to the Log field so Log should never be null here. However the EventSource performs some P/Invoke // interop and creating a System.Type object which happens while running the EventSource ctor can perform // WinRT interop so it is possible that we end up calling IsEnabled before the InteropEventProvider class // constructor has completed so we must check that Log is not null. return Log != null && ((EventSource)Log).IsEnabled(); } #else |
There’s EventSource inside, and one of the things that also did change on my Ubuntu recently was setting an environmental variable: COMPlus_EnableEventLog. It enables tracing events in .NET runtime and I used it for troubleshooting (and a blog post) at some point. The switch doesn’t discriminate and should affect vsdbg-ui as well. What if that’s the problem?
A minute later I remove that environmental variable and VS Code debugger works again.
Conclusion
That’s one of the stories that don’t have satisfying happy ending and still leave many questions unanswered. Why it was using a library compiled for WinRT? There are actually two InteropExtensions implementations in CoreCLR repo and the other one has GetObjectID implemented. Why wasn’t it used instead? Why couldn’t I repeat the issue on brand new Ubuntu and “Hello World” app?
On the other hand, I’ve got my debugger back. You can’t even imagine how stupid it feels to debug with Console.WriteLine.
One thought on “The mystery of “Debug adapter process has terminated unexpectedly””