FileNotFoundException: System.Memory

[BlythMeister]

Description

When running dotnet fake run script.fsx on my machine all is good.
When running on my CI i get this error.

E:\ba1\27cdfea3e3dea91c\.fake-script>dotnet fake run build.fsx
The last restore is still up to date. Nothing left to do.
Performance:
 - Cli parsing: 259 milliseconds
 - Packages: 10 milliseconds
   - Disk IO: 6 milliseconds
   - Average Request Time: 35 milliseconds
   - Number of Requests: 1
   - Creating Runtime Graph: 114 milliseconds
   - Retrieve Assembly List: 641 milliseconds
 - Script analyzing: 201 milliseconds
 - Runtime: 1 second
There was a problem while setting up the environment:
-> One or more errors occurred. (An error occurred while sending the request.)
-> HttpRequestException: An error occurred while sending the request.
-> FileNotFoundException: Could not load file or assembly 'System.Memory, Version=4.0.1.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51'. The system cannotfind the file specified.
Hint: If you just upgraded the fake-runner you can try to remove the .fake directory and try again.

Now, i don't think that this is a FAKE issue per-say, but i can't establish why FAKE is trying to pull System.Memory

This is my script running on my machine vs build agent

[matthid]

You can use paket why to check how why dependency is pulled. If you use "in-line" #r "paket: you can call paket within the .fake/<build.fsx>/ directory.

Generally I'd ask why you get "Last restore is still up to date", I'd not expect that on the CI server.

[BlythMeister]

paket why:

F:\Git\FifteenBelow.Fake [master ≡ +0 ~2 -0 !]> .\.paket\paket.exe why --group FAKE System.Memory   
Paket version 5.181.1                                                                               
NuGet System.Memory - 4.5.1 is a transitive dependency.                                             
It is part of following dependency chains:                                                          
                                                                                                    
-> dotnet-fake - 5.6.1                                                                              
  -> Paket.Core - 5.181.1                                                                           
    -> System.Net.Http.WinHttpHandler - 4.5                                                         
      -> System.Memory - 4.5.1                                                                      
                                                                                                    
... and 4 chains more starting at dotnet-fake ...                                                   
To display all chains use --details flag.                                                           
                                                                                                    
-> FAKE.Core.Target - 5.6.1                                                                         
  -> Fake.Core.Process - 5.6.1                                                                      
    -> System.Diagnostics.Process - 4.3                                                             
      -> Microsoft.Win32.Registry - 4.5                                                             
        -> System.Memory - 4.5.1                                                                    
                                                                                                    
-> FAKE.DotNet.MSBuild - 5.6.1                                                                      
  -> Fake.Core.Process - 5.6.1                                                                      
    -> System.Diagnostics.Process - 4.3                                                             
      -> Microsoft.Win32.Registry - 4.5                                                             
        -> System.Memory - 4.5.1                                                                    
                                                                                                    
-> FAKE.DotNet.Paket - 5.6.1                                                                        
  -> Fake.Core.Process - 5.6.1                                                                      
    -> System.Diagnostics.Process - 4.3                                                             
      -> Microsoft.Win32.Registry - 4.5                                                             
        -> System.Memory - 4.5.1                                                                    
                                                                                                    
-> Fake.Tools.Git - 5.6.1                                                                           
  -> Fake.Core.Process - 5.6.1                                                                      
    -> System.Diagnostics.Process - 4.3                                                             
      -> Microsoft.Win32.Registry - 4.5                                                             
        -> System.Memory - 4.5.1                                                                    
                                                                                                    
-> System.Configuration.ConfigurationManager - 4.5                                                  
  -> System.Security.Cryptography.ProtectedData - 4.5                                               
    -> System.Memory - 4.5.1                                                                        

in my script i do

dotnet restore fake.proj
dotnet fake run build.fsx

with my scripts i am using #r "paket: groupref Fake //"

[BlythMeister]

here is a MVP for what i am using...the script itself is pointless to protect our IP...but hey shows the same issue :)

27cdfea3e3dea91c.zip

This script works on my PC (and other developer PCs) but it doesn't on my CI server....it must be environmental, but i can't work out what...

[matthid]

You can try running with dotnet fake -vv run build.fsx but yeah something is strange here.

[BlythMeister]

i have a full log, but the "interesting bit" i think is this:

-> One or more errors occurred. (An error occurred while sending the request.)
   StackTrace:
        at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
        at Microsoft.FSharp.Control.AsyncResult`1.Commit()
        at Microsoft.FSharp.Control.AsyncPrimitives.RunSynchronouslyInCurrentThread[a](CancellationToken cancellationToken, FSharpAsync`1 computation)
        at Microsoft.FSharp.Control.AsyncPrimitives.RunSynchronously[T](CancellationToken cancellationToken, FSharpAsync`1 computation, FSharpOption`1 timeout)
        at Microsoft.FSharp.Control.FSharpAsync.RunSynchronously[T](FSharpAsync`1 computation, FSharpOption`1 timeout, FSharpOption`1 cancellationToken)
        at Fake.Runtime.FakeRuntime.extractedFolder$cont@197(Lazy`1 paketDependenciesFile, GroupName groupName, String rootDir, PackageName packageName, SemVerInfo version, Unit unitVar) in D:\a\1\s\src\app\Fake.Runtime\FakeRuntime.fs:line 198
        at Fake.Runtime.FakeRuntime.getCurrentSDKReferenceFiles@178(Lazy`1 paketDependenciesFile, GroupName groupName, Unit unitVar0) in D:\a\1\s\src\app\Fake.Runtime\FakeRuntime.fs:line 214
        at Fake.Runtime.FakeRuntime.retrieveInfosUncached@264(String cacheDir, Lazy`1 paketDependenciesFile, VerboseLevel logLevel, GroupName groupName, FrameworkIdentifier framework, Lazy`1 lockFile, Lazy`1 cache, Unit unitVar0) in D:\a\1\s\src\app\Fake.Runtime\FakeRuntime.fs:line 341
        at Fake.Runtime.FakeRuntime.getKnownAssemblies@420(FakeConfig config, String cacheDir, Lazy`1 paketDependenciesFile, VerboseLevel logLevel, GroupName groupName, FrameworkIdentifier framework, FileInfo lockFilePath, String assemblyCacheHashFile, String assemblyCacheFile, Lazy`1 lockFile, Lazy`1 cache, Lazy`1 writeIntellisenseTask, Unit unitVar0) in D:\a\1\s\src\app\Fake.Runtime\FakeRuntime.fs:line 434
        at Fake.Runtime.FakeRuntime.knownAssemblies@439.Invoke(Unit unitVar) in D:\a\1\s\src\app\Fake.Runtime\FakeRuntime.fs:line 439
        at System.Lazy`1.ViaFactory(LazyThreadSafetyMode mode)
        at System.Lazy`1.ExecutionAndPublication(LazyHelper executionAndPublication, Boolean useDefaultConstructor)
        at System.Lazy`1.CreateValue()
        at Fake.Runtime.FakeRuntime.paketCachingProvider(FakeConfig config, String cacheDir, Dependencies paketApi, Lazy`1 paketDependenciesFile, FSharpOption`1 group) in D:\a\1\s\src\app\Fake.Runtime\FakeRuntime.fs:line 160
        at Fake.Runtime.FakeRuntime.prepareFakeScript(FakeConfig config) in D:\a\1\s\src\app\Fake.Runtime\FakeRuntime.fs:line 570
        at Program.runOrBuild(RunArguments args) in D:\a\1\s\src\app\Fake.netcore\Program.fs:line 155
-> HttpRequestException: An error occurred while sending the request.
   StackTrace:
        at Paket.NetUtils._safeGetFromUrl@576-9.Invoke(Exception _arg5) in C:\code\Paket\src\Paket.Core\Common\NetUtils.fs:line 594
        at <StartupCode$FSharp-Core>.$Async.TryWith@1113-1.Invoke(Exception exn)
        at Microsoft.FSharp.Control.AsyncPrimitives.CallFilterThenInvoke[T](AsyncActivation`1 ctxt, FSharpFunc`2 catchFilter, ExceptionDispatchInfo edi)
        at Microsoft.FSharp.Control.Trampoline.Execute(FSharpFunc`2 firstAction)
-> FileNotFoundException: Could not load file or assembly 'System.Memory, Version=4.0.1.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51'. The system cannot find the file specified.

[matthid]

Oh wow so the problem is in the runtime, actually system.runtime should be part of the directory where fake is run from (fake --version prints that)...

[BlythMeister]

this is the full output...output.txt

E:\ba1\27cdfea3e3dea91c\.fake-script>dotnet fake --version
FAKE 5 - F# Make (5.6.1) (this line is written to standard error, see https://github.com/fsharp/FAKE/issues/2066)
FakePath: C:\Users\chris.blyth\.nuget\packages\fake.runtime\5.6.1\lib\netstandard2.0\Fake.Runtime.dll

[matthid]

I bet this only happens with dotnet-fake and no other distribution of fake

[BlythMeister]

it's odd that it only happen on my CI server too....

[BlythMeister]

i manually added the fake-cli tool onto the server using dotnet tool install fake-cli --tool-path fake then called that build.fsx and it worked fine!

So dotnet-fake behaves differently :(

[BlythMeister]

dotnet-fake - <TargetFramework>netcoreapp2.0</TargetFramework>
fake-cli - <TargetFramework>netcoreapp2.1</TargetFramework>

i only have 2.0.3 on build server, another dev who gets this working has 2.0.2...so going in hunt for that installer to see if this is the problem

[BlythMeister]

so...i fixed it...i took C:\Program Files\dotnet\sdk\2.0.2 from my machine and manually put it in place on my build agent...and it works...

Strange that it won't use 2.0.3...could we make dotnet-fake and fake-cli use the same netcore version?

[BlythMeister]

scrap that...it works when i manually run the script...but when teamcity does, same error still :(

[matthid]

We didn't update netcoreapp in dotnet-fake because that is a breaking change.

[matthid]

Can you report this to the dotnet-cli guys, I'd assume this is some bug in the CliToolReference implementation. And I'm pretty positive that you can reproduce this even without paket. I think the runtime/nuget is not restoring all required packages:

I'd assume nuget somehow decides to take one of the marked code-paths.

I wouldn't be surprised if that exact bug is the reason why they decided to introduce cli-tools and bundle all dependencies instead of relying on nuget

[BlythMeister]

but it's coreapp2.0 not 2.1
so it's pulling system.memory in...im so confused

[BlythMeister]

@matthid i can raise it...but i don't know what to say other than...here is an issue and i was told to raise it by the FAKE guys....

[matthid]

I'm pretty positive this should reproduce in a standalone netcoreapp 2.0 application as well you can try that and report that ...

Try creating a new netcoreapp 2.0 application reference paket core and try to trigger a download, bundle it as clitoolreference and try on your ci

[matthid]

Do you have different PATH or DOTNET_ROOT when running on your build server? It's a bit strange that it only reproduces there and only in the ci process (is that correct?)

[BlythMeister]

@matthid it seems to be something in the fake code itself though. Fake appears to try and download the netstandard.library 2.0.2
On my machine (and others) that download is successful.
However, on my CI, the calls to nuget.org fail

My machine (after i delete package from cache)

Starting request to 'https://api.nuget.org/v3/index.json'
Starting request to 'https://api.nuget.org/v3-flatcontainer/netstandard.library/index.json?semVerLevel=2.0.0'
Source 'https://api.nuget.org/v3/index.json' yielded (0): [2.0.3 ; 2.0.2 ; 2.0.1 ; 2.0.0 ; 2.0.0-preview2-25401-01 ; 2.0.0-preview1-25301-01 ; 1.6.1 ; 1.6.1-preview1-24530-04 ; 1.6.0 ; 1.5.0-rc2-24027]
 - Request 'https://api.nuget.org/v3-flatcontainer/netstandard.library/index.json?semVerLevel=2.0.0' finished with: [2.0.3 ; 2.0.2 ; 2.0.1 ; 2.0.0 ; 2.0.0-preview2-25401-01 ; 2.0.0-preview1-25301-01 ; 1.6.1 ; 1.6.1-preview1-24530-04 ; 1.6.0 ; 1.5.0-rc2-24027]

Downloading NETStandard.Library 2.0.2
Starting request to 'https://api.nuget.org/v3/registration3-gz-semver2/netstandard.library/index.json'
Downloading directly from DownloadLink: https://api.nuget.org/v3-flatcontainer/netstandard.library/2.0.2/netstandard.library.2.0.2.nupkg
Downloading from https://api.nuget.org/v3-flatcontainer/netstandard.library/2.0.2/netstandard.library.2.0.2.nupkg to C:\Users\chris.blyth\.nuget\packages\netstandard.library\2.0.2\netstandard.library.2.0.2.nupkg
Download of NETStandard.Library 2.0.2 done in 1 second. (17802 kbit/s, 2 MB)

Build server

Starting request to 'https://api.nuget.org/v3/index.json'

[BlythMeister]

if i manually put the 2.0.2 package into the user cache...or even get add it to the paket dependencies pinned to 2.0.2 everything works!

Its actually always on the CI machine...

[matthid]

I don't understand. Yes fake is downloading netstandard.library outside the regular resolution in order to have reference assemblies in order to compile the script. But the problem is that downloading fails because the runtime is missing/unable to resolve a reference to System.Memory, which should be available to the fake runtime.

The problem is not that the download is not possible on the CI but that a reference is missing (which is a tooling problem/bug)

[BlythMeister]

Well the logging states it's starting download and then get the error on the ci.
As a result of the ci machine not downloading, it then can't reference system.memory (as the reference is not there)
By manually placing the file on disk in the nuget cache, fake doesn't call paket to trigger the download since it already exists.
So once the machine has downloaded 2.0.2 into the cache, the problem goes away.
The odd thing is, that CI machine being unable to download from nuget, but others being able to...

[matthid]

No it's the other way around: It cannot download because missing System.Memory.
System.Memory should be available to fake after restoring dotnet-fake as it is a dependency.

[matthid]

The Fake runtime doesn't even come to the point of compiling or running the script

[matthid]

As I understand the error it is similar as if "Mono-Cecil" would just be missing at some point (another more direct dependency of https://www.nuget.org/packages/dotnet-fake)

[BlythMeister]

Where would system.memory be?

[BlythMeister]

@matthid since you seem to have a better grasp of the cli issue, would you be able to raise it there for me with relevant detail...I'm a bit lost to be honest 🙁

[BlythMeister]

My big query over the dotnet cli being the cause is that it works on 1 machine and not the other...both running the latest .net core and vs tools.

[matthid]

As long as we are not able to reproduce on a second machine I'm not reporting it ;)

[matthid]

And I'm just trying to explain what I know for you to play around and maybe figure out what's going on/reproduce it

[BlythMeister]

Fair enough...I got 10 agents all with the same issue...but equally 3 machines without. So I'm at a loss...
Is there a way to still use paket to get the fake cli...but not use dotnet cli to restore it...

[BlythMeister]

I also really appreciate your help... especially as I don't think this a fake or even paket for that matter issue.

[matthid]

Fair enough...I got 10 agents all with the same issue...but equally 3 machines without.

Interesting, anything they share? Are your agents always clean machines or installed manually?

Is there a way to still use paket to get the fake cli...but not use dotnet cli to restore it...

Let's keep this issue focused on the issue, using dotnet tool is a workaround and not yet supported by paket in any way.

[matthid]

What I would do next is do dotnet restore of the dotnet-fake package with full logging (/verbosity:detailed or /verbosity:diag maybe even binlog) and compare against the working agent (ie search for System.Memory in the log)

Edit: wrong package

[BlythMeister]

I was focused on the running, not the restore...I'll focus more on restore on Monday...or maybe with a beer tonight 😂

All agents are the same...they are VMS from the same image.

[BlythMeister]

i cant see anything special in the logs...
ci-machine-output.txt
dev-machine-output.txt

any ideas...

[matthid]

Can you try to set DotnetCliToolTargetFramework to netcoreapp2.0 in the project file?

[BlythMeister]

YES YES YES YES YES YES YES YES YES YES YES YES YES YES YES

That works!!!!!

[matthid]

What a fucking mess

[matthid]

by the way: NuGet/Home#5067

[BlythMeister]

Oh wow...what a mess!
Maybe worth updating the example repo to include that property.... just incase?

[matthid]

yes indeed

[BlythMeister]

If nothing else...ive learnt that even the new tooling has huge flaws 😂

Thank you for all your help once again, I would never have found that!

[matthid]

Ok I think have updated the relevant places/templates and added a comment to the nuget issue. I'd assume other people will encounter this in the future as well. Thanks for debugging this all the way through. This will be the canonical issue ;). But I'm closing is as I don't see anything else we could do (besides maybe tweeting/bloging about it)