[lldb][tests] Sockets leaks in API tests with a remote target

[slydiman]

We got unexpected errors on a random single test on lldb-remote-linux-ubuntu and lldb-remote-linux-win 1-4 times per day.

Error 1: Unresolved some test with the exception failed to create a socket to the launched debug monitor after 20 tries.
Usually we got this error on the Linux host (lldb-remote-linux-ubuntu), e.g. TestGdbRemoteMemoryAllocation.py, TestNonStop.py, TestGdbRemoteSingleStep.py. But we saw the same error (very rarely) on Windows host (lldb-remote-linux-win) too: TestGdbRemoteHostInfo.py.

Error 2: 600 seconds timeout.
Usually (99%) we got this error on the Windows host (lldb-remote-linux-win) with the test TestModuleLoadedNotifys.py and less often with any other test, e.g. TestLldbGdbServer.py. We also saw the same error (very rarely) on Linux host (lldb-remote-linux-ubuntu) too: TestCancelAttach.py.

I believe that the cause of both issues is the same - leaking sockets.

Error 1 is raised in connect_to_debug_monitor() in gdbremote_testcase.py.
It uses a random port 12000 + random.randint(0, 3999) to launch a new instance of lldb-server gdbserver *:port on the target.
Then it tries to connect to the lldb-server up to 10 times with 0.5 sec delay and terminates the lldb-server if connection failed.
Then it tries another port up to 20 times with a random delay 1-5 seconds to avoid collisions.

We checked netstat during the tests in the beginning and got 164 connections in the state TIME_WAIT between the host and the target:
24 connections to target IP:1234 (platform)
100 connections to target IP:43107 (gdbserver)
40 connections to target IP with a random port
and 2 connections in the state ESTABLISHED.

We checked netstat during the tests after 15 minutes and got 641 connections in the state TIME_WAIT between the host and the target
310 connections to target IP:1234 (platform)
331 connections to target IP:43107 (gdbserver)
and 9 connections in the state ESTABLISHED.

Usually the state TIME_WAIT means timeout 4 minutes before releasing resources.

Both buildbots run tests in 8 threads.

Both buildbots use python 3.12. Note the results with python 3.13 are worse probably due to an incremental GC. The average build/test time with python 3.13 is longer.

Probably increasing MAX_ATTEMPTS = 20 in connect_to_debug_monitor() may be enough to fix the error 1.
But I have no idea how to fix and even debug the error 2. It is very hard to reproduce.

[llvmbot]

@llvm/issue-subscribers-lldb

Author: Dmitry Vasilyev (slydiman)

We got unexpected errors on a random single test on [lldb-remote-linux-ubuntu](https://lab.llvm.org/buildbot/#/builders/195) and [lldb-remote-linux-win](https://lab.llvm.org/staging/#/builders/197) 1-4 times per day.

Error 1: Unresolved some test with the exception failed to create a socket to the launched debug monitor after 20 tries.
Usually we got this error on the Linux host (lldb-remote-linux-ubuntu), e.g. TestGdbRemoteMemoryAllocation.py, TestNonStop.py, TestGdbRemoteSingleStep.py. But we saw the same error (very rarely) on Windows host (lldb-remote-linux-win) too: TestGdbRemoteHostInfo.py.

Error 2: 600 seconds timeout.
Usually (99%) we got this error on the Windows host (lldb-remote-linux-win) with the test TestModuleLoadedNotifys.py and less often with any other test, e.g. TestLldbGdbServer.py. We also saw the same error (very rarely) on Linux host (lldb-remote-linux-ubuntu) too: TestCancelAttach.py.

I believe that the cause of both issues is the same - leaking sockets.

Error 1 is raised in connect_to_debug_monitor() in gdbremote_testcase.py.
It uses a random port 12000 + random.randint(0, 3999) to launch a new instance of lldb-server gdbserver *:port on the target.
Then it tries to connect to the lldb-server up to 10 times with 0.5 sec delay and terminates the lldb-server if connection failed.
Then it tries another port up to 20 times with a random delay 1-5 seconds to avoid collisions.

We checked netstat during the tests in the beginning and got 164 connections in the state TIME_WAIT between the host and the target:
24 connections to target IP:1234 (platform)
100 connections to target IP:43107 (gdbserver)
40 connections to target IP with a random port
and 2 connections in the state ESTABLISHED.

We checked netstat during the tests after 15 minutes and got 641 connections in the state TIME_WAIT between the host and the target
310 connections to target IP:1234 (platform)
331 connections to target IP:43107 (gdbserver)
and 9 connections in the state ESTABLISHED.

Both buildbots run tests in 8 threads.

Both buildbots use python 3.12. Note the results with python 3.13 are worse probably due to an incremental GC. The average build/test time with python 3.13 is longer.

Probably increasing MAX_ATTEMPTS = 20 in connect_to_debug_monitor() may be enough to fix the error 1.
But I have no idea how to fix and even debug the error 2. It is very hard to reproduce.

[slydiman]

@labath, do you have any thoughts/suggestions?

[JDevlieghere]

I have some thought after reading this, but please take them with a grain of salt as I didn't actually look into this problem, and my suggestions might try to solve problems that are somewhat orthogonal...

• To avoid the variance introduced by using a random port, could we key the port off of something unique, like the pid of the (test) process? I suspect we might need more than one port per process and therefore that doesn't work? Maybe there are other tricks to get somewhat of a unique namespace, like reserving different blocks in the 4000 ports and picking one based on the test name or something. The problem I'm trying to solve by this is not so much avoiding the collisions, but making it easier to reproduce these issues once they start happening.
• Instead of retrying after a random amount of time, should we use something like exponential backoff? I'd rather have the test take a lot of time occasionally than fail randomly.

[labath]

• To avoid the variance introduced by using a random port, could we key the port off of something unique, like the pid of the (test) process? I suspect we might need more than one port per process and therefore that doesn't work? Maybe there are other tricks to get somewhat of a unique namespace, like reserving different blocks in the 4000 ports and picking one based on the test name or something. The problem I'm trying to solve by this is not so much avoiding the collisions, but making it easier to reproduce these issues once they start happening.

The problem with that is we can't really assume these ports are only going to be used by us. Anything on the system could decide to open one of those ports. If the port number function of the test, then this could cause a specific test to start failing. The failure would be sort of deterministic, but it would depend on the environment outside of the test that you may not be able to do anything about.

I suppose you could handle this by generating a deterministic sequence of port numbers for each test (which would be tried in turn). That would get around this problem and give you some amount of reproducibility, but I don't think it would be much because the behavior would still depend on the relative speeds of different tests (as well as the external environment).

I think the only solid solution is to avoid guessing a port altogether. We don't do that for local runs -- we just have lldb-server connect to the test (reverse-connect mode). That might not work in all remote setups (e.g. if there are firewalls/nats involved), but it could certainly work sometimes. There are also ways to have lldb-server pick a port and communicate that back to the test. Someone just needs to design and implement it.

[slydiman]

17 hours after #118222 is ok on lldb-remote-linux-ubuntu.

But I see something new on lldb-remote-linux-win. Something is incrementally leaking under Windows. Note all crashes are unrelated to llvm changes and the next build is green.

TIMEOUT: lldb-api::TestModuleLoadedNotifys.py - as usual.

UNRESOLVED: lldb-api::TestGdbRemoteSingleStep.py - Exception: failed to create a socket to the launched debug monitor after 10 tries.

UNRESOLVED: lldb-api::TestIOHandlerResizeNoEditline.py - exit code 0xC0000409 means an assert inside the native python code.

UNRESOLVED: lldb-api::TestModuleLoadedNotifys.py - and a crash (access violation in windows.storage.dll, SHELL32.dll) inside SBDebugger::CreateTarget()

Windows fatal exception: access violation
Thread 0x0000119c (most recent call first):
  File "C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\__init__.py", line 4832 in CreateTarget
  File "C:\buildbot\as-builder-10\lldb-x-aarch64\llvm-project\lldb\test\API\functionalities\target-new-solib-notifications\TestModuleLoadedNotifys.py", line 65 in test_launch_notifications
  File "C:\Python312\Lib\unittest\case.py", line 589 in _callTestMethod
  File "C:\Python312\Lib\unittest\case.py", line 634 in run
  File "C:\Python312\Lib\unittest\case.py", line 690 in __call__
  File "C:\Python312\Lib\unittest\suite.py", line 122 in run
  File "C:\Python312\Lib\unittest\suite.py", line 84 in __call__
  File "C:\Python312\Lib\unittest\suite.py", line 122 in run
  File "C:\Python312\Lib\unittest\suite.py", line 84 in __call__
  File "C:\Python312\Lib\unittest\runner.py", line 240 in run
  File "C:\buildbot\as-builder-10\lldb-x-aarch64\llvm-project\lldb\packages\Python\lldbsuite\test\dotest.py", line 1106 in run_suite
  File "C:\buildbot\as-builder-10\lldb-x-aarch64\llvm-project\lldb\test\API\dotest.py", line 8 in <module>
PLEASE submit a bug report to https://github.com/llvm/llvm-project/issues/ and include the crash backtrace.
Exception Code: 0xC0000005
 wil::details::FeatureImpl<__WilFeatureTraits_Feature_CloudFileCopyHook>::ReportUsage(bool,wil::ReportingKind,unsigned __int64)
 #0 0x00007ff94c151ba9 (C:\Windows\System32\SHELL32.dll+0x61ba9) CallCopyHooks()
 #1 0x00007ff94c1473cb (C:\Windows\System32\SHELL32.dll+0x573cb) SHELL32_CallFileCopyHooks()
 #2 0x00007ff9402fcf19 (C:\Windows\SYSTEM32\windows.storage.dll+0x1ccf19) CFileOperation::CopyHooks(unsigned int, struct IShellItem *, struct IShellItem *, unsigned short const *, unsigned long)
 #3 0x00007ff9402857e1 (C:\Windows\SYSTEM32\windows.storage.dll+0x1557e1) CCopyWorkItem::_UpFrontConfirmations(CCopyWorkItem *__hidden this)
 #4 0x00007ff940284198 (C:\Windows\SYSTEM32\windows.storage.dll+0x154198) CCopyWorkItem::ProcessWorkItem(CCopyWorkItem *__hidden this, IUnknown *punk, int)
 #5 0x00007ff940288bcf (C:\Windows\SYSTEM32\windows.storage.dll+0x158bcf) CRecursiveFolderOperation::Do(CRecursiveFolderOperation *__hidden this)
 #6 0x00007ff940287204 (C:\Windows\SYSTEM32\windows.storage.dll+0x157204) CFileOperation::_EnumRootDo(CFileOperation *__hidden this, struct CEnumOperation *)
 #7 0x00007ff940286cdf (C:\Windows\SYSTEM32\windows.storage.dll+0x156cdf) CFileOperation::PrepareAndDoOperations(CFileOperation *__hidden this)
 #8 0x00007ff94028b692 (C:\Windows\SYSTEM32\windows.storage.dll+0x15b692) SHFileOperationWithAdditionalFlags(struct _SHFILEOPSTRUCTW *)
 #9 0x00007ff9144254de PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x9a54de)
#10 0x00007ff914032d5e PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x5b2d5e)
#11 0x00007ff91403260a PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x5b260a)
#12 0x00007ff9140349f8 PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x5b49f8)
#13 0x00007ff914033d92 PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x5b3d92)
#14 0x00007ff913fcfbca PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x54fbca)
#15 0x00007ff913fd1a3d PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x551a3d)
#16 0x00007ff913fd1f09 PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x551f09)
#17 0x00007ff913fa6a83 PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x526a83)
#18 0x00007ff913f98616 PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x518616)
#19 0x00007ff913fb56d6 PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x5356d6)
#20 0x00007ff913f7def9 PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x4fdef9)
#21 0x00007ff913f7e0e3 PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x4fe0e3)
#22 0x00007ff91446bb5a PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x9ebb5a)
#23 0x00007ff91446ac7f PyInit__lldb (C:\buildbot\as-builder-10\lldb-x-aarch64\build\Lib\site-packages\lldb\_lldb.cp312-win_amd64.pyd+0x9eac7f)
#24 0x00007ff94b2d6b4c (C:\Windows\System32\ucrtbase.dll+0x26b4c)
#25 0x00007ff94d714cb0 (C:\Windows\System32\KERNEL32.DLL+0x14cb0)
#26 0x00007ff94dd7ecdb (C:\Windows\SYSTEM32\ntdll.dll+0x7ecdb)

[slydiman]

I have updated the call stack above with symbols from windows.storage.dll and shell32.dll.
The original _lldb.cp312-win_amd64.pyd file is lost, so it is impossible to reconstruct the full call stack.
But it seems the hang and timeout on Windows host is not related to sockets.

It seems SHFileOperationWithAdditionalFlags() is an alias for SHFileOperationW(). SHFileOperationW() is called from:

• llvm/utils/lit/lit/TestRunner.py, executeBuiltinRm()
• llvm::sys::fs::remove_directories()

llvm::sys::fs::remove_directories() is called from:

• source/Target/ModuleCache.cpp, DeleteExistingModule()
• source/Host/common/HostInfoBase.cpp, ~HostInfoBaseFields()

Note the crash occured in SHELL32_CallFileCopyHooks(). It is very similar to this article.
I will try to add the FOFX_NO­COPY­HOOKS flag to llvm::sys::fs::remove_directories().

[slydiman]

Note the buildbot lldb-aarch64-windows is very unstable.
I see a lot random failures, including timeouts and access violations.
For example https://lab.llvm.org/staging/#/builders/194/builds/5291
Unfortunately it does not contain any stacktrace at all. But it seems to be the same issue.

[slydiman]

wil::details::FeatureImpl<__WilFeatureTraits_Feature_CloudFileCopyHook>::ReportUsage(bool,wil::ReportingKind,unsigned __int64)

Probably this issue on Windows may be fixed by disabling OneDrive and Submit a file for malware analysis option in the builtin antivirus.
We will check it.

[slydiman]

The patch #118222 did not fix the issue on Ubuntu (4 hours between builds):
https://lab.llvm.org/buildbot/#/builders/195/builds/2032
https://lab.llvm.org/buildbot/#/builders/195/builds/2043

Exception: failed to create a socket to the launched debug monitor after 10 tries

[slydiman]

After disabling OneDrive and all Azure Arc and Windows Defender Antivirus related options we have the following statistics on Windows host since this build (3 days):

• 7 timeouts on the test lldb-api::TestModuleLoadedNotifys.py, link
• 2 crashes inside python (exit code 0xC0000409, no stack trace) on the test lldb-api::TestIOHandlerResizeNoEditline.py link1, link2
• 2 times Exception: failed to create a socket to the launched debug monitor after 10 tries, link1, link2

I hope #118677 or #119146 will improve situation. We did not try to change the socket WAIT_TIME timeout in the registry yet.