Failed to create CoreCLR, HRESULT: 0x8007001F on MacOSX

@nbkolchin

From @nbkolchin on Sunday, March 15, 2020 5:05:59 PM

related: #10737

MacOSX: 10.15.3, dotnet installed via brew cask.

Any dotnet cli command in MacOSX fails after starting Windows inside Parallels Desktop. After stopping Parallels, dotnet commands run normally.

bash-3.2$ dotnet --info
Failed to create CoreCLR, HRESULT: 0x8007001F

Host (useful for support):
  Version: 3.1.2
  Commit:  916b5cba26

.NET Core SDKs installed:
  3.1.102 [/usr/local/share/dotnet/sdk]

.NET Core runtimes installed:
  Microsoft.AspNetCore.App 3.1.2 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 3.1.2 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]

To install additional .NET Core runtimes or SDKs:
  https://aka.ms/dotnet-download
bash-3.2$ dotnet fsi
Failed to create CoreCLR, HRESULT: 0x8007001F
bash-3.2$ dotnet run
Failed to create CoreCLR, HRESULT: 0x8007001F

Gist with COREHOST_TRACE: https://gist.github.com/nbkolchin/667e96211531eb277bdb320fcc23fc90

Copied from original issue: dotnet/sdk#10870

@am11

From @am11 on Monday, March 16, 2020 1:03:35 AM

Decoding this error:

**********************************************************************
** Visual Studio 2019 Developer Command Prompt v16.4.2
** Copyright (c) 2019 Microsoft Corporation
**********************************************************************

C:\Program Files (x86)\Microsoft Visual Studio\2019\Community>certutil -error 0x8007001F
0x8007001f (WIN32: 31 ERROR_GEN_FAILURE) -- 2147942431 (-2147024865)
Error message text: A device attached to the system is not functioning.
CertUtil: -error command completed successfully.

reveals that it is ERROR_GEN_FAILURE, and it might be related to CoreCLR not being about to allocate enough memory, when Parallels is running on the system. Here is a similar discussion about FreeBSD getting the same error when VirtualBox is running on the host: #6353 (comment).

cc @janvorli

@nbkolchin

From @nbkolchin on Monday, March 16, 2020 7:20:07 AM

I closed Linux VM and dotnet runs normally. However, this is a bit strange and doesn't look like memory problem according to vm_stat

bash-3.2$ vm_stat
Mach Virtual Memory Statistics: (page size of 4096 bytes)
Pages free:                               15427.
Pages active:                            170566.
Pages inactive:                          168086.
Pages speculative:                         1870.
Pages throttled:                              0.
Pages wired down:                       3307031.
Pages purgeable:                            164.
"Translation faults":                2652199561.
Pages copy-on-write:                  214559536.
Pages zero filled:                   1575362268.
Pages reactivated:                     98113039.
Pages purged:                          55526875.
File-backed pages:                       124505.
Anonymous pages:                         216017.
Pages stored in compressor:             2147461.
Pages occupied by compressor:            530806.
Decompressions:                       104749354.
Compressions:                         144644094.
Pageins:                              170120013.
Pageouts:                               3434494.
Swapins:                               13571981.
Swapouts:                              14414055.
bash-3.2$ dotnet fsi
Failed to create CoreCLR, HRESULT: 0x8007001F

------

bash-3.2$ vm_stat
Mach Virtual Memory Statistics: (page size of 4096 bytes)
Pages free:                                7033.
Pages active:                            647789.
Pages inactive:                          621903.
Pages speculative:                        24851.
Pages throttled:                              0.
Pages wired down:                       2229157.
Pages purgeable:                          35747.
"Translation faults":                2663584840.
Pages copy-on-write:                  214862336.
Pages zero filled:                   1582131837.
Pages reactivated:                     99356682.
Pages purged:                          55918274.
File-backed pages:                       405872.
Anonymous pages:                         888671.
Pages stored in compressor:             2101202.
Pages occupied by compressor:            663028.
Decompressions:                       106543683.
Compressions:                         146861763.
Pageins:                              171531754.
Pageouts:                               3465199.
Swapins:                               13873146.
Swapouts:                              14637865.
bash-3.2$ dotnet --version
3.1.102

In second sample system has less free memory but dotnet runs normally...

P.S. I'm a bit curious why Blender, Libreoffice, Android Studio and R-Studio are able to start at the same time, but dotnet --version fails...

@janvorli

From @janvorli on Thursday, March 19, 2020 12:50:06 AM

The ERROR_GEN_FAILURE can mean a lot of things. It means that something non-specific has failed during CoreCLR PAL initialization, it doesn't have to be related to memory at all.
@nbkolchin would you be willing to try an instrumented version of libcoreclr.dylib that I would create for you and that would print the exact failure location to the console?

@nbkolchin

From @nbkolchin on Thursday, March 19, 2020 5:33:52 AM

Yes. How I can get "instrumented version"?

P.S. I'm not able to reproduce the problem after system reboot, but will try on holidays.

@janvorli

From @janvorli on Monday, March 23, 2020 12:41:37 PM

How I can get "instrumented version"?

I would create one for you and share it via e.g. OneDrive. But let's first wait to see if you can repro the issue again.

@nbkolchin

From @nbkolchin on Monday, March 23, 2020 4:23:55 PM

It is hard to reproduce. But...

bash-3.2$ dotnet --version
3.1.200
bash-3.2$ dotnet --version
Failed to create CoreCLR, HRESULT: 0x8007001F

Notice the updated dotnet version.

@janvorli

From @janvorli on Monday, March 23, 2020 5:09:29 PM

@nbkolchin what did the updated version change? It is less frequent than with the 3.1.102 you've reported a week ago?

@nbkolchin

From @nbkolchin on Monday, March 23, 2020 5:43:42 PM

Nothing changed. The problem is hard to reproduce but exist in all tested versions.

@nbkolchin

From @nbkolchin on Monday, March 23, 2020 5:48:44 PM

The problem is actually more serious than I thought. Published .NET applications also don't work.

bash-3.2$ ./app
Failed to create CoreCLR, HRESULT: 0x8007001F

This makes .NET not a viable solution for cross-platform development and we bet much on it...

@janvorli

From @janvorli on Monday, March 23, 2020 8:37:26 PM

It is not a surprise, as the issue seems to be in the coreclr initialization and that's shared between the dotnet tool execution and any app execution. So it seems you can repro it quite well. Then it seems it would make sense to try to figure out the exact reason for the failure using an instrumented libcoreclr.dylib.
Let me prepare one and share it with you.

@janvorli

From @janvorli on Tuesday, March 24, 2020 10:14:39 AM

@nbkolchin you can get a modified libcoreclr.dylib here: https://1drv.ms/u/s!AkLV4wRkyHYhyRiRIChDXxs8RvQJ?e=NnoGZ0
After downloading it, you need to ungzip it as follows:

gunzip libcoreclr.dylib.gz

Then the easiest way to try it is to use the published version of your app and replace the libcoreclr.dylib in its directory by the one you've just downloaded and ungzipped.

When you run the application, it would still fail, but it should display a different error code that corresponds to the step in the runtime initialization that has failed instead of just this generic failure code. Please share the error code (HRESULT) with me and I'll look it up.

@nbkolchin

From @nbkolchin on Tuesday, March 24, 2020 5:16:46 PM

bash-3.2$ ./app
Failed to create CoreCLR, HRESULT: 0x8007FF02

@janvorli

From @janvorli on Tuesday, March 24, 2020 5:47:27 PM

Hmm, that's interesting. So this is the function that fails:

runtime/src/coreclr/src/pal/src/thread/process.cpp

Lines 3484 to 3531 in 26eb70b

    
           BOOL 
        
           InitializeFlushProcessWriteBuffers() 
        
           { 
        
               _ASSERTE(s_helperPage == 0); 
        
               _ASSERTE(s_flushUsingMemBarrier == 0); 
        
               // Starting with Linux kernel 4.14, process memory barriers can be generated 
        
               // using MEMBARRIER_CMD_PRIVATE_EXPEDITED. 
        
               int mask = membarrier(MEMBARRIER_CMD_QUERY, 0); 
        
               if (mask >= 0 && 
        
                   mask & MEMBARRIER_CMD_PRIVATE_EXPEDITED) 
        
               { 
        
                   // Register intent to use the private expedited command. 
        
                   if (membarrier(MEMBARRIER_CMD_REGISTER_PRIVATE_EXPEDITED, 0) == 0) 
        
                   { 
        
                       s_flushUsingMemBarrier = TRUE; 
        
                       return TRUE; 
        
                   } 
        
               } 
        
               s_helperPage = static_cast<int*>(mmap(0, GetVirtualPageSize(), PROT_READ | PROT_WRITE, MAP_ANONYMOUS | MAP_PRIVATE, -1, 0)); 
        
               if(s_helperPage == MAP_FAILED) 
        
               { 
        
                   return FALSE; 
        
               } 
        
               // Verify that the s_helperPage is really aligned to the GetVirtualPageSize() 
        
               _ASSERTE((((SIZE_T)s_helperPage) & (GetVirtualPageSize() - 1)) == 0); 
        
               // Locking the page ensures that it stays in memory during the two mprotect 
        
               // calls in the FlushProcessWriteBuffers below. If the page was unmapped between 
        
               // those calls, they would not have the expected effect of generating IPI. 
        
               int status = mlock(s_helperPage, GetVirtualPageSize()); 
        
               if (status != 0) 
        
               { 
        
                   return FALSE; 
        
               } 
        
               status = pthread_mutex_init(&flushProcessWriteBuffersMutex, NULL); 
        
               if (status != 0) 
        
               { 
        
                   munlock(s_helperPage, GetVirtualPageSize()); 
        
               } 
        
               return status == 0; 
        
           }

There are three possible failure points there:

mmap failing to map a single page - this sounds very unlikely that the system would not have a single memory page of free memory for dotnet
mlock failing to lock the single page - there is a limit to how much memory a process can lock. It can be controlled e.g. by the ulimit shell command.
pthread_mutex_init failing to initialize a mutex. I also don't see how that could happen.

So I wonder if it is the mlock failing. Can you please share the output of ulimit -a when starting dotnet is failing?

I will also share one more instrumented version of libcoreclr.dylib with you that will report clearly which of those three failures happened and what was the exact error.

@nbkolchin

From @nbkolchin on Tuesday, March 24, 2020 7:14:57 PM

I've tracked problem to mlock() call. See https://gist.github.com/nbkolchin/067fb7adc45f2a084915a1ec17ed5e61

bash-3.2$ g++ test.cpp
bash-3.2$ ./a.out
mlock failed: Resource temporarily unavailable (4096)
FAILURE

But

bash-3.2$ vm_stat
Mach Virtual Memory Statistics: (page size of 4096 bytes)
Pages free:                               74806.
Pages active:                            184860.
Pages inactive:                          184282.
Pages speculative:                          238.
Pages throttled:                              0.
Pages wired down:                       3440295.
Pages purgeable:                          12373.
"Translation faults":                4935133219.
Pages copy-on-write:                  731013643.
Pages zero filled:                   2776350982.
Pages reactivated:                    232121984.
Pages purged:                          94058094.
File-backed pages:                       108974.
Anonymous pages:                         260406.
Pages stored in compressor:             3071434.
Pages occupied by compressor:            309349.
Decompressions:                       247162531.
Compressions:                         331500515.
Pageins:                              328983977.
Pageouts:                               5876590.
Swapins:                               46780653.
Swapouts:                              49548215.

@janvorli

From @janvorli on Wednesday, March 25, 2020 11:43:52 AM

It seems that parallels consume all the wired memory allowed. Wired memory is a memory that's locked (not allowed to be swapped to disk). It seems that the system wide limit is set to 80% of the physical memory. And it is the limit that causes the mlock to fail with EAGAIN.

Looking at your vm_stat results that you've reported before, I can see that without parallels, the "Pages wired down" is 2229157 and with parallels, it is 3307031.
What is the amount of total physical memory on your Mac? Is it 16GB?

@nbkolchin

From @nbkolchin on Wednesday, March 25, 2020 1:06:11 PM

Yes 16GB.

I understand that this is weird MacOSX behaviour. Forcing some pages to swap (i.e. running application that eats some memory) make mlock() work again without stopping parallels or anything else. I.e.

bash-3.2$ dotnet --version
Failed to create CoreCLR, HRESULT: 0x8007001F
bash-3.2$ ./eatram 1073741824
bash-3.2$ dotnet --version
3.1.200

@janvorli

From @janvorli on Wednesday, March 25, 2020 2:13:10 PM

Maybe there is something else running that consumes a lot of wired pages. Even without parallels, the 2229157 pages means that around 8.5GB of wired pages are consumed, which seems to be a lot and close to the limit that is approx 12.8GB on your device. On my Mac, the vm_stat reports only around 1.23GB of wired pages.

I've found the following script to dump wired pages by process sorted by size at https://apple.stackexchange.com/questions/349037/30gb-out-of-32gb-being-used-for-wired-memory

kextstat | awk 'NR==1{ printf "%10s %s\n", $5, $6; } NR!=1{ printf "%10d %s\n", $5, $6; }' | sort -n

@sfoslund

From @sfoslund on Tuesday, April 7, 2020 5:21:03 PM

@janvorli does this issue belong in dotnet/runtime?

@janvorli

From @janvorli on Thursday, April 9, 2020 8:30:06 PM

@sfoslund I am sorry for missing your message. Yes, it belongs there.

It seems we cannot do anything about this issue. It is a problem of other applications that consume all the fixed system wide quota of wired pages, causing us not to be able to lock single memory page in memory. We need that for the FlushProcessBuffers functionality.

@janvorli

We need that for the FlushProcessBuffers functionality.

@janvorli, I was discussing about FlushProcessBuffers Win32 API's suitable Unix counterpart on illumos channel. Folks were not clear and in turn questioned how are mono, java, rust, ruby and other runtimes handling this concept on Unix. Currently, we need to given additional privilege (proc_lock_memory) on top of basic set on illumos distros for CoreCLR, which other runtimes (including mono) do not require afaict.

Navigation Menu

Repository navigation

Failed to create CoreCLR, HRESULT: 0x8007001F on MacOSX #34793

1 remaining item

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

	BOOL
	InitializeFlushProcessWriteBuffers()
	{
	_ASSERTE(s_helperPage == 0);
	_ASSERTE(s_flushUsingMemBarrier == 0);

	// Starting with Linux kernel 4.14, process memory barriers can be generated
	// using MEMBARRIER_CMD_PRIVATE_EXPEDITED.
	int mask = membarrier(MEMBARRIER_CMD_QUERY, 0);
	if (mask >= 0 &&
	mask & MEMBARRIER_CMD_PRIVATE_EXPEDITED)
	{
	// Register intent to use the private expedited command.
	if (membarrier(MEMBARRIER_CMD_REGISTER_PRIVATE_EXPEDITED, 0) == 0)
	{
	s_flushUsingMemBarrier = TRUE;
	return TRUE;
	}
	}

	s_helperPage = static_cast<int*>(mmap(0, GetVirtualPageSize(), PROT_READ \| PROT_WRITE, MAP_ANONYMOUS \| MAP_PRIVATE, -1, 0));

	if(s_helperPage == MAP_FAILED)
	{
	return FALSE;
	}

	// Verify that the s_helperPage is really aligned to the GetVirtualPageSize()
	_ASSERTE((((SIZE_T)s_helperPage) & (GetVirtualPageSize() - 1)) == 0);

	// Locking the page ensures that it stays in memory during the two mprotect
	// calls in the FlushProcessWriteBuffers below. If the page was unmapped between
	// those calls, they would not have the expected effect of generating IPI.
	int status = mlock(s_helperPage, GetVirtualPageSize());

	if (status != 0)
	{
	return FALSE;
	}

	status = pthread_mutex_init(&flushProcessWriteBuffersMutex, NULL);
	if (status != 0)
	{
	munlock(s_helperPage, GetVirtualPageSize());
	}

	return status == 0;
	}

Failed to create CoreCLR, HRESULT: 0x8007001F on MacOSX #34793

Description

Activity

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

1 remaining item

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

sfoslund commented on Apr 9, 2020

janvorli commented on Jul 15, 2020

am11 commented on Jul 16, 2020

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions