Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

PaketRestoreLockFileHash = PaketRestoreCachedHash slow #2796

Closed
TheAngryByrd opened this issue Sep 25, 2017 · 5 comments · Fixed by #2870
Closed

PaketRestoreLockFileHash = PaketRestoreCachedHash slow #2796

TheAngryByrd opened this issue Sep 25, 2017 · 5 comments · Fixed by #2870

Comments

@TheAngryByrd
Copy link
Contributor

Description

Using dotnet restore -v diag it spends a lot of time on PaketRestore :

Target Performance Summary:
        0 ms  ValidateProjects                           1 calls
        0 ms  _GenerateRestoreGraphProjectEntry         11 calls
        0 ms  ValidateToolsVersions                      1 calls
        1 ms  CheckForImplicitPackageReferenceOverridesBeforeRestore  22 calls
        1 ms  _GenerateProjectRestoreGraph              11 calls
        1 ms  _GetRestoreProjectStyle                   33 calls
        2 ms  _GetRestoreTargetFrameworksAsItems        24 calls
        3 ms  _GetRestoreSettingsOverrides              11 calls
        4 ms  _IsProjectRestoreSupported                11 calls
        5 ms  _GenerateRestoreProjectPathItemsPerFramework  17 calls
        7 ms  _GetRestoreSettingsPerFramework           17 calls
       10 ms  _GenerateRestoreSpecs                     11 calls
       10 ms  _GetProjectJsonPath                       33 calls
       13 ms  _GenerateRestoreProjectSpec               11 calls
       18 ms  _GenerateDotnetCliToolReferenceSpecs      11 calls
       21 ms  GetAllRuntimeIdentifiers                  28 calls
       22 ms  ValidateSolutionConfiguration              1 calls
       23 ms  _LoadRestoreGraphEntryPoints               1 calls
       24 ms  _GetRestoreTargetFrameworksOutput         24 calls
       57 ms  _GenerateProjectRestoreGraphPerFramework  17 calls
       65 ms  _GetRestoreSettings                       11 calls
      534 ms  _FilterRestoreGraphProjectInputItems       1 calls
      693 ms  Restore                                    1 calls
      883 ms  _GenerateRestoreProjectPathItems          24 calls
      998 ms  _GenerateRestoreProjectPathWalk           24 calls
     1442 ms  _GetAllRestoreProjectPathItems             1 calls
    28582 ms  _GenerateRestoreDependencies              11 calls
    45459 ms  PaketRestore                              28 calls
    45833 ms  _GenerateRestoreGraph                      1 calls

I narrowed Paket.Restore.targets down to these lines with a large enough lock file (case about 2500 lines) the ReadAllText functions is extremely slow.

    <PropertyGroup Condition="Exists('$(PaketRestoreCacheFile)') ">
      <PaketRestoreCachedHash>$([System.IO.File]::ReadAllText('$(PaketRestoreCacheFile)'))</PaketRestoreCachedHash>
      <PaketRestoreLockFileHash>$([System.IO.File]::ReadAllText('$(PaketLockFilePath)'))</PaketRestoreLockFileHash>
      <PaketRestoreRequired>true</PaketRestoreRequired>
      <PaketRestoreRequired Condition=" '$(PaketRestoreLockFileHash)' == '$(PaketRestoreCachedHash)' ">false</PaketRestoreRequired>
      <PaketRestoreRequired Condition=" '$(PaketRestoreLockFileHash)' == '' ">true</PaketRestoreRequired>
    </PropertyGroup>

Repro steps

Generate a paket.lock file of about 2500 lines long.

Expected behavior

Sonic

Actual behavior

Slow

Known workarounds

This is not a permanent solution but for comparison if i use the built in shasum function on osx/linux:

    <Exec Command="shasum $(PaketRestoreCacheFile) | awk '{ print $1 }' " ConsoleToMSBuild='true'>
        <Output TaskParameter="ConsoleOutput" PropertyName="PaketRestoreCachedHash" />
    </Exec>
    <Exec Command="shasum $(PaketLockFilePath) | awk '{ print $1 }'" ConsoleToMSBuild='true'>
        <Output TaskParameter="ConsoleOutput" PropertyName="PaketRestoreLockFileHash" />
    </Exec>

    <PropertyGroup Condition="Exists('$(PaketRestoreCacheFile)') ">
      <PaketRestoreRequired>true</PaketRestoreRequired>
      <PaketRestoreRequired Condition=" '$(PaketRestoreLockFileHash)' == '$(PaketRestoreCachedHash)' ">false</PaketRestoreRequired>
      <PaketRestoreRequired Condition=" '$(PaketRestoreLockFileHash)' == '' ">true</PaketRestoreRequired>
    </PropertyGroup>
Target Performance Summary:
        0 ms  ValidateProjects                           1 calls
        0 ms  ValidateToolsVersions                      1 calls
        0 ms  _GenerateRestoreGraphProjectEntry         11 calls
        1 ms  CheckForImplicitPackageReferenceOverridesBeforeRestore  22 calls
        1 ms  _GetRestoreProjectStyle                   33 calls
        2 ms  _GenerateProjectRestoreGraph              11 calls
        3 ms  _GetRestoreSettingsOverrides              11 calls
        3 ms  _IsProjectRestoreSupported                11 calls
        4 ms  _GetRestoreTargetFrameworksAsItems        24 calls
        6 ms  _GenerateRestoreProjectPathItemsPerFramework  17 calls
        6 ms  _GetRestoreSettingsPerFramework           17 calls
        9 ms  _GenerateRestoreSpecs                     11 calls
       10 ms  _GetProjectJsonPath                       33 calls
       18 ms  _GenerateRestoreProjectSpec               11 calls
       22 ms  _GenerateDotnetCliToolReferenceSpecs      11 calls
       22 ms  _GetRestoreTargetFrameworksOutput         24 calls
       22 ms  ValidateSolutionConfiguration              1 calls
       24 ms  _LoadRestoreGraphEntryPoints               1 calls
       29 ms  GetAllRuntimeIdentifiers                  28 calls
       66 ms  _GenerateProjectRestoreGraphPerFramework  17 calls
       81 ms  _GetRestoreSettings                       11 calls
      545 ms  _FilterRestoreGraphProjectInputItems       1 calls
      653 ms  Restore                                    1 calls
      892 ms  _GenerateRestoreProjectPathItems          24 calls
     1009 ms  _GenerateRestoreProjectPathWalk           24 calls
     1455 ms  _GetAllRestoreProjectPathItems             1 calls
     2781 ms  _GenerateRestoreDependencies              11 calls
     3697 ms  PaketRestore                              28 calls
     4120 ms  _GenerateRestoreGraph                      1 calls
@matthid
Copy link
Member

matthid commented Sep 25, 2017

I have no idea why a simple read on a file with 3k lines would take as long as this. Basically all we want is a way to check if something changed.

This is the only practical cross-platform way I could come up with. As nice as such unix tricks are you cannot really assume that shasum awk or other tricks are available.

  • I tried inline C# but that is not working on netcore.
  • I thought about bundling a C# dll but that makes my head hurt.
  • I tried to come up with any better way by trying to hash the file in msbuild.

Please feel free to send a solution as I couldn't find one, sorry. I give up on this one (I never noticed such slowdowns so I guess you have a slow hard drive? Or it is a osx/linux problem?)

@TheAngryByrd
Copy link
Contributor Author

TheAngryByrd commented Sep 25, 2017

Unless my ssd is going bye bye that shouldn't be the issue. Yeah maybe this should be pushed upstream. I also looked for some simple tricks like file size but you're right finding a crossplat solution is not simple.

@TheAngryByrd
Copy link
Contributor Author

Fired up my windows box, yeah this seems local to at least osx. :sad_panda:

@TheAngryByrd
Copy link
Contributor Author

TheAngryByrd commented Oct 19, 2017

Something a bit more x-plat for osx/linux. Just check for the existence of shasum and awk. If they aren't there just fallback to normal

    <!-- Try to find shasum and awk -->
    <PropertyGroup>
        <PaketRestoreCachedHasher Condition="'$(OS)' != 'Windows_NT' And '$(PaketRestoreCachedHasher)' == '' And Exists('/usr/bin/shasum') And Exists('/usr/bin/awk')">/usr/bin/shasum $(PaketRestoreCacheFile) | /usr/bin/awk '{ print $1 }'</PaketRestoreCachedHasher>
        <PaketRestoreLockFileHasher Condition="'$(OS)' != 'Windows_NT' And '$(PaketRestoreLockFileHash)' == '' And Exists('/usr/bin/shasum') And Exists('/usr/bin/awk')">/usr/bin/shasum $(PaketLockFilePath) | /usr/bin/awk '{ print $1 }'</PaketRestoreLockFileHasher>
    </PropertyGroup>


    <!-- If shasum and awk exist get the hashes -->
    <Exec Condition=" '$(PaketRestoreCachedHasher)' != '' " Command="$(PaketRestoreCachedHasher)" ConsoleToMSBuild='true'>
        <Output TaskParameter="ConsoleOutput" PropertyName="PaketRestoreCachedHash" />
    </Exec>
    <Exec Condition=" '$(PaketRestoreLockFileHasher)' != '' " Command="$(PaketRestoreLockFileHasher)" ConsoleToMSBuild='true'>
        <Output TaskParameter="ConsoleOutput" PropertyName="PaketRestoreLockFileHash" />
    </Exec>

    <PropertyGroup Condition="Exists('$(PaketRestoreCacheFile)') ">
      <!-- if no hash has been done yet fall back to just reading in file -->
      <PaketRestoreCachedHash Condition=" '$(PaketRestoreCachedHash)' == '' ">$([System.IO.File]::ReadAllText('$(PaketRestoreCacheFile)'))</PaketRestoreCachedHash>
      <PaketRestoreLockFileHash Condition=" '$(PaketRestoreLockFileHash)' == '' ">$([System.IO.File]::ReadAllText('$(PaketLockFilePath)'))</PaketRestoreLockFileHash>
      <PaketRestoreRequired>true</PaketRestoreRequired>
      <PaketRestoreRequired Condition=" '$(PaketRestoreLockFileHash)' == '$(PaketRestoreCachedHash)' ">false</PaketRestoreRequired>
      <PaketRestoreRequired Condition=" '$(PaketRestoreLockFileHash)' == '' ">true</PaketRestoreRequired>
    </PropertyGroup>

@TheAngryByrd
Copy link
Contributor Author

Bleh. Just noticed you'll get output like

  49ca48de7cc92b2bf9f9ae4cfc4f7707c87f855e
  49ca48de7cc92b2bf9f9ae4cfc4f7707c87f855e
  Paket version 5.119.0
  Performance:
   - Disk IO: 513 milliseconds
   - Runtime: 11 seconds

Why are we using msbuild again? :trollface:

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants